Ready to process requests. rad_recv: Access-Request packet from host 112.196.9.83 port 4072, id=50, length= 254 User-Name = "78-9E-D0-31-29-7E" NAS-IP-Address = 112.196.9.83 NAS-Port = 77 Service-Type = Login-User Acct-Session-Id = "3900001A" 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 = 0x706a00003e2b0000c62d000095580000 MS-CHAP2-Response = 0x8700ea600000fe4300002a4b00005b60000000000000000000 008fe443ec212f221201a7e44c0924d69039f7cd3d835c1e81 # 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 '[[:<:]]%{NA S-Port}[[:>:]]' -> SELECT radius_group_name from raduserzone where site_id='100051' and mac_address='78-9E-D0-31-29-7E' and vlan_id regexp '[[:<:]]77[[:>:]]' rlm_sql (sql): Reserving sql socket id: 48 sql_xlat finished rlm_sql (sql): Released sql socket id: 48 expand: %{sql: SELECT radius_group_name from raduserzone where site_id='%{NAS-Identifier}' and mac_address='%{ Calling-Station-Id}' and vlan_id regexp '[[:<:]]%{NA S-Port}[[:>:]]'} -> 78-9E-D0-31-29-7E +++} # 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 group name='%{Tmp-String-0}' where username='%{Calling-Sta tion-Id}' -> update radusergroup set groupname='78 -9E-D0-31-29-7E' where username='78-9E-D0-31-2 9-7E' rlm_sql (sql): Reserving sql socket id: 47 rlm_sql (sql): Released sql socket id: 47 expand: %{sql:update radusergroup set group name='%{Tmp-String-0}' where username='%{Calling-Sta tion-Id}'} -> 1 ++++} # update request = noop +++} # if (&Tmp-String-0) = noop ++} # 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: 46 [sql] expand: SELECT id, username, attribute, value, op FROM radchec k WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE usern ame = '78-9E-D0-31-29-7E' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radrepl y WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE usern ame = '78-9E-D0-31-29-7E' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE use rname = '%{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 F ROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgro upcheck WHERE groupname = '78-9E-D0-31-29-7E' ORDER BY id [sql] User found in group 78-9E-D0-31-29-7E [sql] expand: SELECT id, groupname, attribute, value, op F ROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgro upreply WHERE groupname = '78-9E-D0-31-29-7E' ORDER BY id rlm_sql (sql): Released sql socket id: 46 ++[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 SNAP3TestRad ius port 77 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, pas s, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password} }', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpo stauth (username, pass, reply, authdate) VALUES ( '78-9E-D0-31-29-7E', '', 'Access-Accept', '2016-06-06 07:39: 54') 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-06 07:39:54') rlm_sql (sql): Reserving sql socket id: 45 rlm_sql (sql): Released sql socket id: 45 ++[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 (userna me, pass, reply, authdate) VALUES ('%{User-Name}', '%{Use r-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S'); -> INSER T INTO radpostauth (username, pass, reply, authdate) VALUE S ('78-9E-D0-31-29-7E', 'Chap-Password', 'Access-Accept', '2016-06-06 07:39:54'); [sql_log] expand: /var/log/radius/radacct/sql-relay -> /var/log/radius/rad acct/sql-relay ++[sql_log] = ok ++[exec] = noop +} # group post-auth = ok Sending Access-Accept of id 50 to 112.196.9.83 port 4072 Nomadix-Expiration = "2016-06-07T11:39:53Z" Nomadix-Group-Bw-Max-Up = 2048 Nomadix-Group-Bw-Max-Down = 2048 Nomadix-Group-Bw-Policy-Id = 3221886 Nomadix-Qos-Policy = "2" Nomadix-SMTP-Redirect = 1 MS-CHAP2-Success = 0x87533d464545443744384531423041463541313632434139354 13342314631383344433132303534423742 MS-MPPE-Recv-Key = 0x3c1af7f1bf20130568017495e60e3a82 MS-MPPE-Send-Key = 0xe12b42b12bf64714163cbb3ada523643 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 Finished request 1. 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=124, le ngth=194 User-Name = "78-9E-D0-31-29-7E" NAS-IP-Address = 112.196.9.83 NAS-Port = 77 Acct-Status-Type = Start Acct-Session-Id = "3900001A" Event-Timestamp = "Jun 6 2016 07:39:54 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 = 77,NAS-Identifier = "100051",NAS-IP-Address = 112.196.9.83,Acct-Session-Id = "3900001A",User-Name = "78-9E-D0-31-29-7E"' [acct_unique] Acct-Unique-Session-ID = "2810ad444390e3f1". ++[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, ac ctuniqueid, username, realm, nasipaddress, naspo rtid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinf o_stop, acctinputoctets, acctoutputoctets, calledstationid, calli ngstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessi onsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Ses sion-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-A ddress}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Ser vice-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-7 E attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 124 to 112.196.9.83 port 4060 Finished request 2. Cleaning up request 2 ID 124 with timestamp +257 Going to the next request Waking up in 4.2 seconds. Cleaning up request 1 ID 50 with timestamp +256 Ready to process requests. rad_recv: Accounting-Request packet from host 112.196.9.83 port 4060, id=126, 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 = "3900001A" Acct-Output-Octets = 30119 Acct-Input-Octets = 45722 Acct-Output-Packets = 104 Acct-Input-Packets = 167 Event-Timestamp = "Jun 6 2016 07:41:22 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 = 89 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 = 0 # 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 = "3900001A",User-Name = "78-9E-D0-31-29-7E"' [acct_unique] Acct-Unique-Session-ID = "0a15fc2e36e14dcb". ++[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} -> 89 [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> 45722 [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> 30119 [sql] expand: %{Acct-Delay-Time} -> 0 [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-06 07:41:23', acctsessiontime = '89', acctinputoctets = '0' << 32 | '45722', 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 126 to 112.196.9.83 port 4060 Finished request 3. Cleaning up request 3 ID 126 with timestamp +345 Going to the next request Ready to process requests. rad_recv: Access-Request packet from host 112.196.9.83 port 4072, id=52, 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 = "3900001B" 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 = 0xd266000079660000bf260000ac620000 MS-CHAP2-Response = 0x8800081500007b2e0000352100008d3e00000000000000000000ac75a3c65d868f5419a8264e1d499378911c6d14314be8a1 # 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 ++} # 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-06 07:41:24') 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-06 07:41:24') 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-06 07:41:24'); [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 52 to 112.196.9.83 port 4072 MS-CHAP2-Success = 0x88533d32383938353231323744434438413342393641424246454345454144444541373344304239463343 MS-MPPE-Recv-Key = 0x5d02393773842b8d0602609f541bfb47 MS-MPPE-Send-Key = 0x6fe63aca3e819a30e0c466e512ff3419 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=128, 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 = "3900001B" Event-Timestamp = "Jun 6 2016 07:41:24 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 = 0 # 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 = "3900001B",User-Name = "78-9E-D0-31-29-7E"' [acct_unique] Acct-Unique-Session-ID = "36546454b3c4c10a". ++[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} -> 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: 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 128 to 112.196.9.83 port 4060 Finished request 5. Cleaning up request 5 ID 128 with timestamp +347 Going to the next request Waking up in 3.9 seconds. Cleaning up request 4 ID 52 with timestamp +346 Ready to process requests. rad_recv: Accounting-Request packet from host 112.196.9.83 port 4060, id=130, length=230 User-Name = "B0-10-41-CA-1E-8D" NAS-IP-Address = 112.196.9.83 NAS-Port = 93 Acct-Status-Type = Stop Acct-Session-Id = "39000019" Acct-Output-Octets = 2301974 Acct-Input-Octets = 14865453 Acct-Output-Packets = 13805 Acct-Input-Packets = 17352 Event-Timestamp = "Jun 6 2016 07:43:36 EDT" Called-Station-Id = "00-50-E8-00-92-24" Calling-Station-Id = "B0-10-41-CA-1E-8D" Acct-Session-Time = 2499 Acct-Terminate-Cause = Idle-Timeout NAS-Identifier = "100051" Framed-IP-Address = 192.168.70.22 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 = "39000019",User-Name = "B0-10-41-CA-1E-8D"' [acct_unique] Acct-Unique-Session-ID = "d18f9c409b649940". ++[acct_unique] = ok [suffix] No '@' in User-Name = "B0-10-41-CA-1E-8D", 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} -> B0-10-41-CA-1E-8D [sql] sql_set_user escaped user --> 'B0-10-41-CA-1E-8D' [sql] expand: %{Acct-Session-Time} -> 2499 [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> 14865453 [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> 2301974 [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-06 07:43:37', acctsessiontime = '2499', acctinputoctets = '0' << 32 | '14865453', acctoutputoctets = ' rlm_sql (sql): Reserving sql socket id: 37 rlm_sql (sql): Released sql socket id: 37 ++[sql] = ok ++[exec] = noop [attr_filter.accounting_response] expand: %{User-Name} -> B0-10-41-CA-1E-8D attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] = updated +} # group accounting = updated Sending Accounting-Response of id 130 to 112.196.9.83 port 4060 Finished request 6. Cleaning up request 6 ID 130 with timestamp +479 Going to the next request Ready to process requests.