radius authentication query not rejecting AUTH
Amardeep Singh
aman.xsaintz at gmail.com
Mon Jun 6 13:59:54 CEST 2016
Hi,
Greetings. Hope you all are doing great!
Following is the authentication query that I am using :-
if ("%{Called-Station-Id}" =~ /^00-50-E8-/) {
update request {
Tmp-String-0 = "%{sql: SELECT radius_group_name from raduserzone where \
site_id='%{NAS-Identifier}' and \
mac_address='%{Calling-Station-Id}' \
and vlan_id regexp '[[:<:]]%{NAS-Port}[[:>:]]'}"
}
if (&Tmp-String-0) {
update request {
Tmp-String-1 := "%{sql:update radusergroup set \
groupname='%{Tmp-String-0}' \
where username='%{Calling-Station-Id}'}";
}
}
}
Also tried if (&Tmp-String-0 != "") { in the above query.
The initial record that we have in the table is a follows :-
mysql> select * from raduserzone;
+----+---------+-------------------+---------+-------------------+
| id | site_id | mac_address | vlan_id | radius_group_name |
+----+---------+-------------------+---------+-------------------+
| 1 | 100051 | 78-9E-D0-31-29-7E | 77,678 | 78-9E-D0-31-29-7E |
+----+---------+-------------------+---------+-------------------+
Now when we try to switch the SSID to Guest space (VLAN_ID = 93) , the
authentication query(above) did not seem to work as expected and it returns
true every time we switch irrespective of the record in the raduserzone
table.
I have attached the debug logs file. On line 267 it says 'SQL query did not
return any results' but still it updates the radusergroup table with a
null value resulting in successfull AUTH on radius. It is not rejecting the
AUTH somehow. Please suggest!
I have already checked the mysql logs and the queries are working fine, if
ran manually.
Thanks
-------------- next part --------------
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/<via Auth-Type = MSCHAP>] (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/<via Auth-Type = MSCHAP>] (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.
More information about the Freeradius-Users
mailing list