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='%{NAS-Port}' ->  SELECT radius_group_name from raduserzone where                               site_id='100051' and                            mac_address='78-9E-D0-31-29-7E' and                          vlan_id='77'
rlm_sql (sql): Reserving sql socket id: 36
SQL query did not return any results
rlm_sql (sql): Released sql socket id: 36
        expand: %{sql: SELECT radius_group_name from raduserzone where                          site_id='%{NAS-Identifier}' and                                 mac_address='%{Calling-Station-Id}' and                              vlan_id='%{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: 35
rlm_sql_mysql: MYSQL Error: No Fields
rlm_sql_mysql: MYSQL error:
rlm_sql (sql): Attempting to connect rlm_sql_mysql #35
rlm_sql_mysql: Starting connect to MySQL server for #35
rlm_sql (sql): Connected new DB handle, #35
rlm_sql (sql): failed after re-connect
SQL query did not succeed
rlm_sql (sql): Released sql socket id: 35
        expand: %{sql: update radusergroup set                             groupname='%{Tmp-String-0}'                             where username='%{Calling-Station-Id}'} ->
++++} # update request = noop
+++} # if (&Tmp-String-0 != "") = noop
+++ ... skipping else for request 7: Preceding "if" was taken
++} # if ("%{Called-Station-Id}" =~ /^00-50-E8-/) = noop
++[chap] = noop
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] = ok
[suffix] No '@' in User-Name = "78-9E-D0-31-29-7E", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] = noop
[eap] No EAP-Message, not doing EAP
++[eap] = noop
++? if ((User-Name =~ /%{Calling-Station-Id}/i) && (User-Name =~ /^(c0-33-5e-57)/i))
        expand: %{Calling-Station-Id} -> 78-9E-D0-31-29-7E
?? Evaluating (User-Name =~ /%{Calling-Station-Id}/i) -> TRUE
?? Evaluating (User-Name =~ /^(c0-33-5e-57)/i) -> FALSE
++? if ((User-Name =~ /%{Calling-Station-Id}/i) && (User-Name =~ /^(c0-33-5e-57)/i)) -> FALSE
[files]         expand: %{Calling-Station-Id} -> 78-9E-D0-31-29-7E
++[files] = noop
[sql]   expand: %{User-Name} -> 78-9E-D0-31-29-7E
[sql] sql_set_user escaped user --> '78-9E-D0-31-29-7E'
rlm_sql (sql): Reserving sql socket id: 34
[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
rlm_sql (sql): Released sql socket id: 34
++[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 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, 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-04-22 02:15:09')
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-04-22 02:15:09')
rlm_sql (sql): Reserving sql socket id: 33
rlm_sql (sql): Released sql socket id: 33
++[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-04-22 02:15:09');
[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 10 to 112.196.9.83 port 2939
        MS-CHAP2-Success = 0x2c533d44433637373633323830393933464333434445433636414535424641414645343143363532383739
        MS-MPPE-Recv-Key = 0xcacc2558ba80ad6bac2e68d769718b11
        MS-MPPE-Send-Key = 0xb0ee2cb548a13fba8e0fbebcfee26f72
        MS-MPPE-Encryption-Policy = 0x00000001
        MS-MPPE-Encryption-Types = 0x00000006
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host 112.196.9.83 port 3404, id=18, length=189
        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 = "33000006"
        Event-Timestamp = "Apr 22 2016 02:15:09 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 = "0.0.0.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 = 77,NAS-Identifier = "100051",NAS-IP-Address = 112.196.9.83,Acct-Session-Id = "33000006",User-Name = "78-9E-D0-31-29-7E"'
[acct_unique] Acct-Unique-Session-ID = "598ef65abf72768f".
++[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: 32
rlm_sql (sql): Released sql socket id: 32
++[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 18 to 112.196.9.83 port 3404
Finished request 8.
Cleaning up request 8 ID 18 with timestamp +2357
Going to the next request
Waking up in 4.1 seconds.
Cleaning up request 7 ID 10 with timestamp +2356
Ready to process requests.