problems with mac auth and huntgroups
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?
participants (1)
-
Eric Doutreleau