problems with mac auth and huntgroups

Eric Doutreleau Eric.Doutreleau at it-sudparis.eu
Wed Mar 16 17:05:24 CET 2011


Hi

i m using freeradius 2.1.10
i have setup mac auth based authentication like it s written here
http://wiki.freeradius.org/Mac-Auth

it works quite well

my problems is now i want to combine that with huntgroups

i have put in my /etc/raddb/huntgroups
the following line

radfiltuxmacs   NAS-IP-Address == 157.159.7.108, NAS-Port-Id == 19-21

and i have modified the authorized_macs this way

00188bd041e4 	Huntgroup-Name == "radfiltuxmacs"
	Tunnel-Type := VLAN,
	Tunnel-Medium-Type := IEEE-802,
	Tunnel-Private-Group-Id := 15,
	Fall-Through = no

with the Huntgroup-Name it doesn't works

here is the log
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] Received Access-Request 
packet from host 157.159.7.108 port 1025, id=38, leng
th=197
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Framed-MTU = 1466
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	NAS-IP-Address = 157.159.7.108
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	NAS-Identifier = "radfilsw"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	User-Name = "00188bd041e4"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Service-Type = Framed-User
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Framed-Protocol = PPP
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	NAS-Port = 20
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	NAS-Port-Type = Ethernet
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	NAS-Port-Id = "20"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Called-Station-Id = 
"00-23-47-33-7e-ec"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Calling-Station-Id = 
"00-18-8b-d0-41-e4"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Connect-Info = "CONNECT 
Ethernet 100Mbps Full duplex"
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	CHAP-Password = 
0x14d8e8e4d846868af6005c652fa9294207
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] 	Message-Authenticator = 
0x3f7d3084a4e8c0e1507b1b196132d645
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] # Executing section 
authorize from file /etc/raddb/sites-enabled/default
Wed Mar 16 16:19:55 2011 : Debug: [<thread>] +- entering group authorize 
{...}
Wed Mar 16 16:19:55 2011 : Debug: ++[preprocess] returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++- entering policy 
rewrite_calling_station_id {...}
Wed Mar 16 16:19:55 2011 : Debug: +++? if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i)
Wed Mar 16 16:19:55 2011 : Debug: ? Evaluating 
(request:Calling-Station-Id =~ /([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-
f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: +++? if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: +++- entering if 
(request:Calling-Station-Id =~ /([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0
-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) {...}
Wed Mar 16 16:19:55 2011 : Debug: 	expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 
00188bd041e4
Wed Mar 16 16:19:55 2011 : Debug: ++++[request] returns ok
Wed Mar 16 16:19:55 2011 : Debug: +++- if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) returns ok
Wed Mar 16 16:19:55 2011 : Debug: +++ ... skipping else for request 0: 
Preceding "if" was taken
Wed Mar 16 16:19:55 2011 : Debug: ++- policy rewrite_calling_station_id 
returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++? if (User-Name =~ 
/^%{Calling-Station-ID}$/i)
Wed Mar 16 16:19:55 2011 : Debug: 	expand: ^%{Calling-Station-ID}$ -> 
^00188bd041e4$
Wed Mar 16 16:19:55 2011 : Debug: ? Evaluating (User-Name =~ 
/^%{Calling-Station-ID}$/i) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++? if (User-Name =~ 
/^%{Calling-Station-ID}$/i) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++- entering if (User-Name =~ 
/^%{Calling-Station-ID}$/i) {...}
Wed Mar 16 16:19:55 2011 : Debug: +++[control] returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++- if (User-Name =~ 
/^%{Calling-Station-ID}$/i) returns ok
Wed Mar 16 16:19:55 2011 : Debug: [auth_log] 	expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
  /var/log/radius/radacct/157.159.7.108/auth-detail-20110316
Wed Mar 16 16:19:55 2011 : Debug: [auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /v
ar/log/radius/radacct/157.159.7.108/auth-detail-20110316
Wed Mar 16 16:19:55 2011 : Debug: [auth_log] 	expand: %t -> Wed Mar 16 
16:19:55 2011
Wed Mar 16 16:19:55 2011 : Debug: ++[auth_log] returns ok
Wed Mar 16 16:19:55 2011 : Debug: [chap] WARNING: Auth-Type already set. 
  Not setting to CHAP
Wed Mar 16 16:19:55 2011 : Debug: ++[chap] returns noop
Wed Mar 16 16:19:55 2011 : Debug: ++[mschap] returns noop
Wed Mar 16 16:19:55 2011 : Debug: [suffix] No '@' in User-Name = 
"00188bd041e4", looking up realm NULL
Wed Mar 16 16:19:55 2011 : Debug: [suffix] Found realm "NULL"
Wed Mar 16 16:19:55 2011 : Debug: [suffix] Adding Stripped-User-Name = 
"00188bd041e4"
Wed Mar 16 16:19:55 2011 : Debug: [suffix] Adding Realm = "NULL"
Wed Mar 16 16:19:55 2011 : Debug: [suffix] Authentication realm is LOCAL.
Wed Mar 16 16:19:55 2011 : Debug: ++[suffix] returns ok
Wed Mar 16 16:19:55 2011 : Debug: [eap] No EAP-Message, not doing EAP
Wed Mar 16 16:19:55 2011 : Debug: ++[eap] returns noop
Wed Mar 16 16:19:55 2011 : Debug: [files] users: Matched entry DEFAULT 
at line 31
Wed Mar 16 16:19:55 2011 : Debug: ++[files] returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++[expiration] returns noop
Wed Mar 16 16:19:55 2011 : Debug: ++[logintime] returns noop
Wed Mar 16 16:19:55 2011 : Debug: [pap] WARNING! No "known good" 
password found for the user.  Authentication may fail bec
ause of this.
Wed Mar 16 16:19:55 2011 : Debug: ++[pap] returns noop
Wed Mar 16 16:19:55 2011 : Debug: Found Auth-Type = CSID
Wed Mar 16 16:19:55 2011 : Debug: # Executing group from file 
/etc/raddb/sites-enabled/default
Wed Mar 16 16:19:55 2011 : Debug: +- entering group CSID {...}
Wed Mar 16 16:19:55 2011 : Debug: ++? if (Chap-Password)
Wed Mar 16 16:19:55 2011 : Debug: ? Evaluating (Chap-Password) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++? if (Chap-Password) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++- entering if (Chap-Password) {...}
Wed Mar 16 16:19:55 2011 : Debug: 	expand: %{User-Name} -> 00188bd041e4
Wed Mar 16 16:19:55 2011 : Debug: +++[control] returns reject
Wed Mar 16 16:19:55 2011 : Debug: [chap] login attempt by "00188bd041e4" 
with CHAP password
Wed Mar 16 16:19:55 2011 : Debug: [chap] Using clear text password 
"00188bd041e4" for user 00188bd041e4 authentication.
Wed Mar 16 16:19:55 2011 : Debug: [chap] chap user 00188bd041e4 
authenticated succesfully
Wed Mar 16 16:19:55 2011 : Debug: +++[chap] returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++- if (Chap-Password) returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++ ... skipping else for request 0: 
Preceding "if" was taken
Wed Mar 16 16:19:55 2011 : Debug: # Executing section post-auth from 
file /etc/raddb/sites-enabled/default
Wed Mar 16 16:19:55 2011 : Debug: +- entering group post-auth {...}
Wed Mar 16 16:19:55 2011 : Debug: [sql] 	expand: %{User-Name} -> 
00188bd041e4
Wed Mar 16 16:19:55 2011 : Debug: [sql] sql_set_user escaped user --> 
'00188bd041e4'
Wed Mar 16 16:19:55 2011 : Debug: [sql] 	expand: %{User-Password} ->
Wed Mar 16 16:19:55 2011 : Debug: [sql] 	... expanding second conditional
Wed Mar 16 16:19:55 2011 : Debug: [sql] 	expand: %{Chap-Password} -> 
0x14d8e8e4d846868af6005c652fa9294207
Wed Mar 16 16:19:55 2011 : Debug: [sql] 	expand: INSERT INTO radpostauth 
                           (username, pass,
  reply, authdate)                           VALUES ( 
         '%{User-Name}',                           '
%{%{User-Password}:-%{Chap-Password}}', 
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
                            (username, pass, reply, authdate) 
                 VALUES (
'00188bd041e4', 
'0x14d8e8e4d846868af6005c652fa9294207', 
'Access-Accept
', '2011-03-16 16:19:55')
Wed Mar 16 16:19:55 2011 : Debug: ++[sql] returns ok
Wed Mar 16 16:19:55 2011 : Debug: ++[exec] returns noop
Wed Mar 16 16:19:55 2011 : Debug: ++? if (control:Auth-Type == 'CSID')
Wed Mar 16 16:19:55 2011 : Debug: ? Evaluating (control:Auth-Type == 
'CSID') -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++? if (control:Auth-Type == 'CSID') 
-> TRUE
Wed Mar 16 16:19:55 2011 : Debug: ++- entering if (control:Auth-Type == 
'CSID') {...}
Wed Mar 16 16:19:55 2011 : Debug: [authorized_macs] 	expand: 
%{Calling-Station-ID} -> 00188bd041e4
Wed Mar 16 16:19:55 2011 : Debug: +++[authorized_macs.authorize] returns 
noop
Wed Mar 16 16:19:55 2011 : Debug: +++? if (!ok)
Wed Mar 16 16:19:55 2011 : Debug: ? Evaluating !(ok) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: +++? if (!ok) -> TRUE
Wed Mar 16 16:19:55 2011 : Debug: +++- entering if (!ok) {...}
Wed Mar 16 16:19:55 2011 : Debug: ++++[reject] returns reject
Wed Mar 16 16:19:55 2011 : Debug: +++- if (!ok) returns reject
Wed Mar 16 16:19:55 2011 : Debug: ++- if (control:Auth-Type == 'CSID') 
returns reject
Wed Mar 16 16:19:55 2011 : Debug: Using Post-Auth-Type Reject
Wed Mar 16 16:19:55 2011 : Debug: # Executing group from file 
/etc/raddb/sites-enabled/default
Wed Mar 16 16:19:55 2011 : Debug: +- entering group REJECT {...}
Wed Mar 16 16:19:55 2011 : Debug: [attr_filter.access_reject] 	expand: 
%{User-Name} -> 00188bd041e4
Wed Mar 16 16:19:55 2011 : Debug: ++[attr_filter.access_reject] returns 
updated
Wed Mar 16 16:19:55 2011 : Debug: Delaying reject of request 0 for 1 seconds
Wed Mar 16 16:19:56 2011 : Debug: Sending delayed reject for request 0
Wed Mar 16 16:19:56 2011 : Debug: Sending Access-Reject packet to host 
157.159.7.108 port 1025, id=38, length=0
Wed Mar 16 16:20:01 2011 : Debug: Cleaning up request 0 ID 38 with 
timestamp +42

without the huntgroup-name it does work
here is the log
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] Received Access-Request 
packet from host 157.159.7.108 port 1025, id=34, leng
th=197
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Framed-MTU = 1466
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-IP-Address = 157.159.7.108
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Identifier = "radfilsw"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	User-Name = "00188bd041e4"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Service-Type = Framed-User
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Framed-Protocol = PPP
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Port = 20
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Port-Type = Ethernet
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Port-Id = "20"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Called-Station-Id = 
"00-23-47-33-7e-ec"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Calling-Station-Id = 
"00-18-8b-d0-41-e4"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Connect-Info = "CONNECT 
Ethernet 100Mbps Full duplex"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	CHAP-Password = 
0x12c06b04fb50151e8b4f43a769d3a04351
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Message-Authenticator = 
0x6241a99d53380476bba649bedb8ee760
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] # Executing section 
authorize from file /etc/raddb/sites-enabled/default
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] +- entering group authorize 
{...}
Wed Mar 16 16:14:13 2011 : Debug: ++[preprocess] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++- entering policy 
rewrite_calling_station_id {...}
Wed Mar 16 16:14:13 2011 : Debug: +++? if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i)
Wed Mar 16 16:14:13 2011 : Debug: ? Evaluating 
(request:Calling-Station-Id =~ /([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-
f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: +++? if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: +++- entering if 
(request:Calling-Station-Id =~ /([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0
-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) {...}
Wed Mar 16 16:14:13 2011 : Debug: 	expand: %{1}%{2}%{3}%{4}%{5}%{6} -> 
00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: ++++[request] returns ok
Wed Mar 16 16:14:13 2011 : Debug: +++- if (request:Calling-Station-Id =~ 
/([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2}
)[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})[-:]?([0-9a-f]{2})/i) returns ok
Wed Mar 16 16:14:13 2011 : Debug: +++ ... skipping else for request 0: 
Preceding "if" was taken
Wed Mar 16 16:14:13 2011 : Debug: ++- policy rewrite_calling_station_id 
returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++? if (User-Name =~ 
/^%{Calling-Station-ID}$/i)
Wed Mar 16 16:14:13 2011 : Debug: 	expand: ^%{Calling-Station-ID}$ -> 
^00188bd041e4$
Wed Mar 16 16:14:13 2011 : Debug: ? Evaluating (User-Name =~ 
/^%{Calling-Station-ID}$/i) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++? if (User-Name =~ 
/^%{Calling-Station-ID}$/i) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++- entering if (User-Name =~ 
/^%{Calling-Station-ID}$/i) {...}
Wed Mar 16 16:14:13 2011 : Debug: +++[control] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++- if (User-Name =~ 
/^%{Calling-Station-ID}$/i) returns ok
Wed Mar 16 16:14:13 2011 : Debug: [auth_log] 	expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
  /var/log/radius/radacct/157.159.7.108/auth-detail-20110316
Wed Mar 16 16:14:13 2011 : Debug: [auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /v
ar/log/radius/radacct/157.159.7.108/auth-detail-20110316
Wed Mar 16 16:14:13 2011 : Debug: [auth_log] 	expand: %t -> Wed Mar 16 
16:14:13 2011
Wed Mar 16 16:14:13 2011 : Debug: ++[auth_log] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [chap] WARNING: Auth-Type already set. 
  Not setting to CHAP
Wed Mar 16 16:14:13 2011 : Debug: ++[chap] returns noop
Wed Mar 16 16:14:13 2011 : Debug: ++[mschap] returns noop
Wed Mar 16 16:14:13 2011 : Debug: [suffix] No '@' in User-Name = 
"00188bd041e4", looking up realm NULL
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Found realm "NULL"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Adding Stripped-User-Name = 
"00188bd041e4"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Adding Realm = "NULL"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Authentication realm is LOCAL.
Wed Mar 16 16:14:13 2011 : Debug: ++[suffix] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [eap] No EAP-Message, not doing EAP
Wed Mar 16 16:14:13 2011 : Debug: ++[eap] returns noop
Wed Mar 16 16:14:13 2011 : Debug: [files] users: Matched entry DEFAULT 
at line 31
Wed Mar 16 16:14:13 2011 : Debug: ++[files] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++[expiration] returns noop
Wed Mar 16 16:14:13 2011 : Debug: ++[logintime] returns noop
Wed Mar 16 16:14:13 2011 : Debug: [pap] WARNING! No "known good" 
password found for the user.  Authentication may fail bec
ause of this.
Wed Mar 16 16:14:13 2011 : Debug: ++[pap] returns noop
Wed Mar 16 16:14:13 2011 : Debug: Found Auth-Type = CSID
Wed Mar 16 16:14:13 2011 : Debug: # Executing group from file 
/etc/raddb/sites-enabled/default
Wed Mar 16 16:14:13 2011 : Debug: +- entering group CSID {...}
Wed Mar 16 16:14:13 2011 : Debug: ++? if (Chap-Password)
Wed Mar 16 16:14:13 2011 : Debug: ? Evaluating (Chap-Password) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++? if (Chap-Password) -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++- entering if (Chap-Password) {...}
Wed Mar 16 16:14:13 2011 : Debug: 	expand: %{User-Name} -> 00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: +++[control] returns reject
Wed Mar 16 16:14:13 2011 : Debug: [chap] login attempt by "00188bd041e4" 
with CHAP password
Wed Mar 16 16:14:13 2011 : Debug: [chap] Using clear text password 
"00188bd041e4" for user 00188bd041e4 authentication.
Wed Mar 16 16:14:13 2011 : Debug: [chap] chap user 00188bd041e4 
authenticated succesfully
Wed Mar 16 16:14:13 2011 : Debug: +++[chap] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++- if (Chap-Password) returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++ ... skipping else for request 0: 
Preceding "if" was taken
Wed Mar 16 16:14:13 2011 : Debug: # Executing section post-auth from 
file /etc/raddb/sites-enabled/default
Wed Mar 16 16:14:13 2011 : Debug: +- entering group post-auth {...}
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: %{User-Name} -> 
00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: [sql] sql_set_user escaped user --> 
'00188bd041e4'
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: %{User-Password} ->
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	... expanding second conditional
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: %{Chap-Password} -> 
0x12c06b04fb50151e8b4f43a769d3a04351
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: INSERT INTO radpostauth 
                           (username, pass,
  reply, authdate)                           VALUES ( 
         '%{User-Name}',                           '
%{%{User-Password}:-%{Chap-Password}}', 
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
                            (username, pass, reply, authdate) 
                 VALUES (
'00188bd041e4', 
'0x12c06b04fb50151e8b4f43a769d3a04351', 
'Access-Accept
', '2011-03-16 16:14:13')
Wed Mar 16 16:14:13 2011 : Debug: ++[sql] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++[exec] returns noop
Wed Mar 16 16:14:13 2011 : Debug: ++? if (control:Auth-Type == 'CSID')
Wed Mar 16 16:14:13 2011 : Debug: ? Evaluating (control:Auth-Type == 
'CSID') -> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++? if (control:Auth-Type == 'CSID') 
-> TRUE
Wed Mar 16 16:14:13 2011 : Debug: ++- entering if (control:Auth-Type == 
'CSID') {...}
Wed Mar 16 16:14:13 2011 : Debug: [authorized_macs] 	expand: 
%{Calling-Station-ID} -> 00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: [authorized_macs] users: Matched entry 
00188bd041e4 at line 1
Wed Mar 16 16:14:13 2011 : Debug: +++[authorized_macs.authorize] returns ok
Wed Mar 16 16:14:13 2011 : Debug: +++? if (!ok)
Wed Mar 16 16:14:13 2011 : Debug: ? Evaluating !(ok) -> FALSE
Wed Mar 16 16:14:13 2011 : Debug: +++? if (!ok) -> FALSE
Wed Mar 16 16:14:13 2011 : Debug: ++- if (control:Auth-Type == 'CSID') 
returns ok
Wed Mar 16 16:14:13 2011 : Debug: Sending Access-Accept packet to host 
157.159.7.108 port 1025, id=34, length=0
Wed Mar 16 16:14:13 2011 : Debug: 	Tunnel-Type:0 := VLAN
Wed Mar 16 16:14:13 2011 : Debug: 	Tunnel-Medium-Type:0 := IEEE-802
Wed Mar 16 16:14:13 2011 : Debug: 	Tunnel-Private-Group-Id:0 := "15"
Wed Mar 16 16:14:13 2011 : Debug: Finished request 0.
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] Received Accounting-Request 
packet from host 157.159.7.108 port 1033, id=35,
length=113
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Acct-Session-Id = 
"008C00000008"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Acct-Status-Type = Start
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Acct-Authentic = RADIUS
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Acct-Delay-Time = 0
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Port = 20
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Calling-Station-Id = 
"00-18-8B-D0-41-E4"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	Service-Type = Framed-User
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-IP-Address = 157.159.7.108
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	NAS-Identifier = "radfilsw"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] 	User-Name = "00188bd041e4"
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] # Executing section preacct 
from file /etc/raddb/sites-enabled/default
Wed Mar 16 16:14:13 2011 : Debug: [<thread>] +- entering group preacct {...}
Wed Mar 16 16:14:13 2011 : Debug: ++[preprocess] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [acct_unique] Hashing 'NAS-Port = 
20,Client-IP-Address = 157.159.7.108,NAS-IP-Address =
157.159.7.108,Acct-Session-Id = "008C00000008",User-Name = "00188bd041e4"'
Wed Mar 16 16:14:13 2011 : Debug: [acct_unique] Acct-Unique-Session-ID = 
"dc3de5f2391ff6ae".
Wed Mar 16 16:14:13 2011 : Debug: ++[acct_unique] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [suffix] No '@' in User-Name = 
"00188bd041e4", looking up realm NULL
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Found realm "NULL"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Adding Stripped-User-Name = 
"00188bd041e4"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Adding Realm = "NULL"
Wed Mar 16 16:14:13 2011 : Debug: [suffix] Accounting realm is LOCAL.
Wed Mar 16 16:14:13 2011 : Debug: ++[suffix] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++[files] returns noop
Wed Mar 16 16:14:13 2011 : Debug: # Executing section accounting from 
file /etc/raddb/sites-enabled/default
Wed Mar 16 16:14:13 2011 : Debug: +- entering group accounting {...}
Wed Mar 16 16:14:13 2011 : Debug: [detail] 	expand: 
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var
/log/radius/radacct/157.159.7.108/detail-20110316
Wed Mar 16 16:14:13 2011 : Debug: [detail] 
/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to 
/var/log/
radius/radacct/157.159.7.108/detail-20110316
Wed Mar 16 16:14:13 2011 : Debug: [detail] 	expand: %t -> Wed Mar 16 
16:14:13 2011
Wed Mar 16 16:14:13 2011 : Debug: ++[detail] returns ok
Wed Mar 16 16:14:13 2011 : Debug: ++[unix] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [radutmp] 	expand: 
/var/log/radius/radutmp -> /var/log/radius/radutmp
Wed Mar 16 16:14:13 2011 : Debug: [radutmp] 	expand: %{User-Name} -> 
00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: ++[radutmp] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: %{User-Name} -> 
00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: [sql] sql_set_user escaped user --> 
'00188bd041e4'
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand: %{Acct-Delay-Time} -> 0
Wed Mar 16 16:14:13 2011 : Debug: [sql] 	expand:            INSERT INTO 
radacct             (acctsessionid,    acct
uniqueid,     username,              realm,            nasipaddress, 
  nasportid,              nasporttype,      acctsta
rttime,    acctstoptime,              acctsessiontime,  acctauthentic, 
   connectinfo_start,              connectinfo_stop
, acctinputoctets,  acctoutputoctets,              calledstationid, 
callingstationid, acctterminatecause,              se
rvicetype,      framedprotocol,   framedipaddress, 
acctstartdelay,   acctstopdelay,    xascendsessionsvrkey)
           VALUES             ('%{Acct-Session-Id}', 
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
      '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', 
'%{NAS-Port-Type}', '%S', NULL,              '0', '%{Acc
t-Authentic}', '%{Connect-Info}',              '', '0', '0', 
   '%{Called-Station-Id}', '%{Calling-Station-Id}',
  '',              '%{Service-Type}', '%{Framed-Protoco
Wed Mar 16 16:14:13 2011 : Debug: ++[sql] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] Processing sql_log_accounting
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] 	expand: %{User-Name} -> 
00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] 	expand: 
%{%{User-Name}:-DEFAULT} -> 00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] sql_set_user escaped user 
--> '00188bd041e4'
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] 	expand: INSERT INTO radacct 
(AcctSessionId, UserName, 	 NASIPAddress, Fra
medIPAddress, AcctStartTime, AcctStopTime, 	 AcctSessionTime, 
AcctTerminateCause) VALUES                 	 ('%{Acct-
Session-Id}', '%{User-Name}', '%{NAS-IP-Address}', 	 
'%{Framed-IP-Address}', '%S', '0', '0', ''); -> INSERT INTO radac
ct (AcctSessionId, UserName, 	 NASIPAddress, FramedIPAddress, 
AcctStartTime, AcctStopTime, 	 AcctSessionTime, AcctTerm
inateCause) VALUES                 	 ('008C00000008', '00188bd041e4', 
'157.159.7.108', 	 '', '2011-03-16 16:14:13'
, '0', '0', '');
Wed Mar 16 16:14:13 2011 : Debug: [sql_log] 	expand: 
/var/log/radius/radacct/sql-relay -> /var/log/radius/radacct/sql-r
elay
Wed Mar 16 16:14:13 2011 : Debug: ++[sql_log] returns ok
Wed Mar 16 16:14:13 2011 : Debug: [attr_filter.accounting_response] 
expand: %{User-Name} -> 00188bd041e4
Wed Mar 16 16:14:13 2011 : Debug: ++[attr_filter.accounting_response] 
returns updated
Wed Mar 16 16:14:13 2011 : Debug: Sending Accounting-Response packet to 
host 157.159.7.108 port 1033, id=35, length=0
Wed Mar 16 16:14:13 2011 : Debug: Finished request 1.
Wed Mar 16 16:14:14 2011 : Debug: Cleaning up request 1 ID 35 with 
timestamp +44
Wed Mar 16 16:14:18 2011 : Debug: Cleaning up request 0 ID 34 with 
timestamp +44

does someone know if it s possible to use hungroups this way?




More information about the Freeradius-Users mailing list