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