++[suffix] = noop ++[files] = noop +} # group preacct = ok # Executing section accounting from file /etc/raddb/sites-enabled/default +group accounting { [sql] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E' [sql] expand: %{Acct-Delay-Time} -> 0 [sql] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, 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', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', rlm_sql (sql): Reserving sql socket id: 44 rlm_sql (sql): Released sql socket id: 44 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> 78-9E-D0-31-29-7E attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 192 to 112.196.9.83 port 4060 Finished request 2. Cleaning up request 2 ID 192 with timestamp +101 Going to the next request Waking up in 4.1 seconds. Cleaning up request 1 ID 68 with timestamp +100 Ready to process requests. rad_recv: Accounting-Request packet from host 112.196.9.83 port 4060, id=194, length=275 User-Name = "78-9E-D0-31-29-7E" NAS-IP-Address = 112.196.9.83 NAS-Port = 93 Acct-Status-Type = Stop Acct-Session-Id = "39000023" Acct-Output-Octets = 37383 Acct-Input-Octets = 216389 Acct-Output-Packets = 295 Acct-Input-Packets = 275 Event-Timestamp = "Jun 7 2016 01:26:05 EDT" Nomadix-Group-Bw-Policy-Id = 3221886 Nomadix-Group-Bw-Max-Up = 2048 Nomadix-Group-Bw-Max-Down = 2048 Nomadix-Qos-Policy = "2" Called-Station-Id = "00-50-E8-00-92-24" Calling-Station-Id = "78-9E-D0-31-29-7E" Acct-Session-Time = 35 Acct-Terminate-Cause = Admin-Reset NAS-Identifier = "100051" Framed-IP-Address = 192.168.20.3 Nomadix-Subnet = "192.168.20.0" Nomadix-SMTP-Redirect = 1 WISPr-Location-ID = "isocc=,cc=,ac=,network=" Acct-Delay-Time = 1 # Executing section preacct from file /etc/raddb/sites-enabled/default +group preacct { ++[preprocess] = ok [acct_unique] Hashing 'NAS-Port = 93,NAS-Identifier = "100051",NAS-IP-Address = 112.196.9.83,Acct-Session-Id = "39000023",User-Name = "78-9E-D0-31-29-7E"' [acct_unique] Acct-Unique-Session-ID = "523a3a36f4d7e8b1". ++[acct_unique] = ok [suffix] No '@' in User-Name = "78-9E-D0-31-29-7E", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop ++[files] = noop +} # group preacct = ok # Executing section accounting from file /etc/raddb/sites-enabled/default +group accounting { [sql] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E' [sql] expand: %{Acct-Session-Time} -> 35 [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> 216389 [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> 37383 [sql] expand: %{Acct-Delay-Time} -> 1 [sql] expand: UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{%{Acct-Session-Time}:-0}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET acctstoptime = '2016-06-07 01:26:06', acctsessiontime = '35', acctinputoctets = '0' << 32 | '216389', acctoutputoctets = '0' < rlm_sql (sql): Reserving sql socket id: 43 rlm_sql (sql): Released sql socket id: 43 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> 78-9E-D0-31-29-7E attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 194 to 112.196.9.83 port 4060 Finished request 3. Cleaning up request 3 ID 194 with timestamp +135 Going to the next request Ready to process requests. rad_recv: Access-Request packet from host 112.196.9.83 port 4072, id=70, length=254 User-Name = "78-9E-D0-31-29-7E" NAS-IP-Address = 112.196.9.83 NAS-Port = 93 Service-Type = Login-User Acct-Session-Id = "39000024" Called-Station-Id = "00-50-E8-00-92-24" Calling-Station-Id = "78-9E-D0-31-29-7E" Nomadix-Logoff-URL = "http://1.1.1.1" WISPr-Location-ID = "isocc=,cc=,ac=,network=" NAS-Identifier = "100051" Framed-IP-Address = 192.168.20.3 MS-CHAP-Challenge = 0x636700004b0e0000e203000026760000 MS-CHAP2-Response = 0x9100462e0000a0640000fb2e00001324000000000000000000009aaed039d60ff05a5115de0f6210f7a795541df62e03fe87 # Executing section authorize from file /etc/raddb/sites-enabled/default +group authorize { ++[preprocess] = ok ++? if ("%{Called-Station-Id}" =~ /^00-50-E8-/) expand: %{Called-Station-Id} -> 00-50-E8-00-92-24 ? Evaluating ("%{Called-Station-Id}" =~ /^00-50-E8-/) -> TRUE ++? if ("%{Called-Station-Id}" =~ /^00-50-E8-/) -> TRUE ++if ("%{Called-Station-Id}" =~ /^00-50-E8-/) { +++update request { sql_xlat expand: %{User-Name} -> 78-9E-D0-31-29-7E sql_set_user escaped user --> '78-9E-D0-31-29-7E' expand: SELECT radius_group_name from raduserzone where site_id='%{NAS-Identifier}' and mac_address='%{Calling-Station-Id}' and vlan_id regexp '[[:<:]]%{NAS-Port}[[:>:]]' -> SELECT radius_group_name from raduserzone where site_id='100051' and mac_address='78-9E-D0-31-29-7E' and vlan_id regexp '[[:<:]]93[[:>:]]' rlm_sql (sql): Reserving sql socket id: 42 SQL query did not return any results rlm_sql (sql): Released sql socket id: 42 expand: %{sql: SELECT radius_group_name from raduserzone where site_id='%{NAS-Identifier}' and mac_address='%{Calling-Station-Id}' and vlan_id regexp '[[:<:]]%{NAS-Port}[[:>:]]'} -> +++} # update request = noop +++? if (&Tmp-String-0 != "") ? Evaluating (&Tmp-String-0 != "") -> TRUE +++? if (&Tmp-String-0 != "") -> TRUE +++if (&Tmp-String-0 != "") { ++++update request { sql_xlat expand: %{User-Name} -> 78-9E-D0-31-29-7E sql_set_user escaped user --> '78-9E-D0-31-29-7E' expand: update radusergroup set groupname='%{Tmp-String-0}' where username='%{Calling-Station-Id}' -> update radusergroup set groupname='' where username='78-9E-D0-31-29-7E' rlm_sql (sql): Reserving sql socket id: 41 rlm_sql (sql): Released sql socket id: 41 expand: %{sql:update radusergroup set groupname='%{Tmp-String-0}' where username='%{Calling-Station-Id}'} -> 1 ++++} # update request = noop +++} # if (&Tmp-String-0 != "") = noop +++ ... skipping else for request 4: Preceding "if" was taken ++} # if ("%{Called-Station-Id}" =~ /^00-50-E8-/) = noop ++[chap] = noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] = ok [suffix] No '@' in User-Name = "78-9E-D0-31-29-7E", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop [eap] No EAP-Message, not doing EAP ++[eap] = noop ++? if ((User-Name =~ /%{Calling-Station-Id}/i) && (User-Name =~ /^(c0-33-5e-57)/i)) expand: %{Calling-Station-Id} -> 78-9E-D0-31-29-7E ?? Evaluating (User-Name =~ /%{Calling-Station-Id}/i) -> TRUE ?? Evaluating (User-Name =~ /^(c0-33-5e-57)/i) -> FALSE ++? if ((User-Name =~ /%{Calling-Station-Id}/i) && (User-Name =~ /^(c0-33-5e-57)/i)) -> FALSE [files] expand: %{Calling-Station-Id} -> 78-9E-D0-31-29-7E ++[files] = noop [sql] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E' rlm_sql (sql): Reserving sql socket id: 40 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '78-9E-D0-31-29-7E' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '78-9E-D0-31-29-7E' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '78-9E-D0-31-29-7E' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '' ORDER BY id [sql] User found in group [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '' ORDER BY id rlm_sql (sql): Released sql socket id: 40 ++[sql] = ok ++[expiration] = noop ++[logintime] = noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] = noop +} # group authorize = ok Found Auth-Type = MSCHAP # Executing group from file /etc/raddb/sites-enabled/default +group MS-CHAP { [mschap] Creating challenge hash with username: 78-9E-D0-31-29-7E [mschap] Client is using MS-CHAPv2 for 78-9E-D0-31-29-7E, we need NT-Password [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] = ok +} # group MS-CHAP = ok expand: %{NAS-IP-Address} -> 112.196.9.83 Login OK: [78-9E-D0-31-29-7E/] (from client SNAP3TestRadius port 93 cli 78-9E-D0-31-29-7E) 112.196.9.83 # Executing section post-auth from file /etc/raddb/sites-enabled/default +group post-auth { [sql] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [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 ( '78-9E-D0-31-29-7E', '', 'Access-Accept', '2016-06-07 01:26:06') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '78-9E-D0-31-29-7E', '', 'Access-Accept', '2016-06-07 01:26:06') rlm_sql (sql): Reserving sql socket id: 39 rlm_sql (sql): Released sql socket id: 39 ++[sql] = ok [sql_log] Processing sql_log_postauth [sql_log] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql_log] expand: %{%{User-Name}:-DEFAULT} -> 78-9E-D0-31-29-7E [sql_log] sql_set_user escaped user --> '78-9E-D0-31-29-7E' [sql_log] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [sql_log] ... expanding second conditional [sql_log] expand: Chap-Password -> Chap-Password [sql_log] 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 ('78-9E-D0-31-29-7E', 'Chap-Password', 'Access-Accept', '2016-06-07 01:26:06'); [sql_log] expand: /var/log/radius/radacct/sql-relay -> /var/log/radius/radacct/sql-relay ++[sql_log] = ok ++[exec] = noop +} # group post-auth = ok Sending Access-Accept of id 70 to 112.196.9.83 port 4072 MS-CHAP2-Success = 0x91533d33354635393230313644353938413244363441423845373032344244374630433242364138453836 MS-MPPE-Recv-Key = 0x214a4ca4ca7c015f64dd6a68a9e45a8b MS-MPPE-Send-Key = 0xf4cf5d3f60c6ed5ecf583256a7c2510f MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 Finished request 4. Going to the next request Waking up in 4.9 seconds. rad_recv: Accounting-Request packet from host 112.196.9.83 port 4060, id=196, length=194 User-Name = "78-9E-D0-31-29-7E" NAS-IP-Address = 112.196.9.83 NAS-Port = 93 Acct-Status-Type = Start Acct-Session-Id = "39000024" Event-Timestamp = "Jun 7 2016 01:26:06 EDT" Called-Station-Id = "00-50-E8-00-92-24" Calling-Station-Id = "78-9E-D0-31-29-7E" NAS-Identifier = "100051" Framed-IP-Address = 192.168.20.3 Nomadix-Subnet = "192.168.20.0" Nomadix-SMTP-Redirect = 1 WISPr-Location-ID = "isocc=,cc=,ac=,network=" Acct-Delay-Time = 1 # Executing section preacct from file /etc/raddb/sites-enabled/default +group preacct { ++[preprocess] = ok [acct_unique] Hashing 'NAS-Port = 93,NAS-Identifier = "100051",NAS-IP-Address = 112.196.9.83,Acct-Session-Id = "39000024",User-Name = "78-9E-D0-31-29-7E"' [acct_unique] Acct-Unique-Session-ID = "b9fe1a746ff197cb". ++[acct_unique] = ok [suffix] No '@' in User-Name = "78-9E-D0-31-29-7E", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] = noop ++[files] = noop +} # group preacct = ok # Executing section accounting from file /etc/raddb/sites-enabled/default +group accounting { [sql] expand: %{User-Name} -> 78-9E-D0-31-29-7E [sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E' [sql] expand: %{Acct-Delay-Time} -> 1 [sql] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, 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', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', rlm_sql (sql): Reserving sql socket id: 38 rlm_sql (sql): Released sql socket id: 38 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> 78-9E-D0-31-29-7E attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 196 to 112.196.9.83 port 4060 Finished request 5. Cleaning up request 5 ID 196 with timestamp +136 Going to the next request Waking up in 3.8 seconds. Cleaning up request 4 ID 70 with timestamp +135