Class Attribute Missing for Anonymous Users

Selahattin Cilek selahattin_cilek at hotmail.com
Sat Sep 23 07:16:33 CEST 2017



On 21.09.2017 23:06, Alan DeKok wrote:
> On Sep 21, 2017, at 3:31 PM, Selahattin Cilek <selahattin_cilek at hotmail.com> wrote:
>> I use FreeRADIUS 3.0.15 and for some strange reason, the Unifi APs
>> refuse to append the Class attribute for those users that use anonymous
>> identity.
>>
>> Here are 4 accounting packets that were generated by the same UAP for
>> the same user. When she does not use anonymous identity, we see the
>> Class attribute. But when she *does* use anonymous identity, the Class
>> attribute goes missing:
>    That's not good.
>
>> I think the UAP is trying to protect the user's privacy and I hate that.
>    It's not supposed to be smart.  It's supposed to do what the RADIUS server tells it to do.
>
>> I will definitely get in touch with Ubnt and ask them to change this
>> behaviour.
>    That's the best approach.
>
>> But is there anything I can do on the FreeRADIUS server to
>> make sure that the Class attribute is present in all accounting packets?
>    No.  The AP creates the accounting packets.  No amount of poking FreeRADIUS will fix a broken AP.
>
>    Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

I installed FreeRADIUS 2.2.9 and copied the configuration of a running 
site and ran some tests. I am afraid that does not happen with 
FreeRADIUS 2.2.9. So I believe it has something to do with the 
configuration of FreeRADIUS 3.0.15.


  Module: Linked to module rlm_mschap
  Module: Instantiating module "mschap" from file 
/usr/local/etc/raddb/modules/mschap
   mschap {
         use_mppe = yes
         require_encryption = no
         require_strong = no
         with_ntdomain_hack = yes
         allow_retry = yes
   }
  Module: Instantiating module "motp" from file 
/usr/local/etc/raddb/modules/motp
   exec motp {
         wait = yes
         program = "/usr/local/bin/bash 
/usr/local/etc/raddb/scripts/otpverify.sh %{request:User-Name} 
%{request:User-Password} %{reply:MOTP-Init-Secret} %{rep
ly:MOTP-PIN} %{reply:MOTP-Offset}"
         input_pairs = "request"
         shell_escape = yes
   }
  Module: Linked to module rlm_digest
  Module: Instantiating module "digest" from file 
/usr/local/etc/raddb/modules/digest
  Module: Linked to module rlm_unix
  Module: Instantiating module "unix" from file 
/usr/local/etc/raddb/modules/unix
   unix {
         radwtmp = "/var/log/radwtmp"
   }
  Module: Linked to module rlm_eap
  Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf
   eap {
         default_eap_type = "ttls"
         timer_expire = 60
         ignore_unknown_eap_types = no
         cisco_accounting_username_bug = no
         max_sessions = 4096
   }
  Module: Linked to sub-module rlm_eap_tls
  Module: Instantiating eap-tls
    tls {
         rsa_key_exchange = no
         dh_key_exchange = yes
         rsa_key_length = 512
         dh_key_length = 512
         verify_depth = 0
         CA_path = "/usr/local/etc/raddb/certs"
         pem_file_type = yes
         private_key_file = "/usr/local/etc/raddb/certs/server_key.pem"
         certificate_file = "/usr/local/etc/raddb/certs/server_cert.pem"
         CA_file = "/usr/local/etc/raddb/certs/ca_cert.pem"
         dh_file = "/usr/local/etc/raddb/certs/dh"
         random_file = "/usr/local/etc/raddb/certs/random"
         fragment_size = 1024
         include_length = yes
         check_crl = no
         check_all_crl = no
         cipher_list = "DEFAULT"
         ecdh_curve = "prime256v1"
     cache {
         enable = no
         lifetime = 24
         max_entries = 255
     }
     verify {
     }
     ocsp {
         enable = no
         override_cert_url = no
         url = "http://127.0.0.1/ocsp/"
         use_nonce = yes
         timeout = 0
         softfail = no
     }
    }
  Module: Linked to sub-module rlm_eap_ttls
  Module: Instantiating eap-ttls
    ttls {
         default_eap_type = "tls"
         copy_request_to_tunnel = yes
         use_tunneled_reply = yes
         include_length = yes
    }
  Module: Linked to sub-module rlm_eap_peap
  Module: Instantiating eap-peap
    peap {
         default_eap_type = "tls"
         copy_request_to_tunnel = yes
         use_tunneled_reply = yes
         proxy_tunneled_request_as_eap = yes
         soh = no
    }
  Module: Linked to sub-module rlm_eap_mschapv2
  Module: Instantiating eap-mschapv2
    mschapv2 {
         with_ntdomain_hack = no
         send_error = no
    }
  Module: Checking authorize {...} for more modules to load
  Module: Linked to module rlm_preprocess
  Module: Instantiating module "preprocess" from file 
/usr/local/etc/raddb/modules/preprocess
   preprocess {
         huntgroups = "/usr/local/etc/raddb/huntgroups"
         hints = "/usr/local/etc/raddb/hints"
         with_ascend_hack = no
         ascend_channels_per_line = 23
         with_ntdomain_hack = no
         with_specialix_jetstream_hack = no
         with_cisco_vsa_hack = no
         with_alvarion_vsa_hack = no
   }
reading pairlist file /usr/local/etc/raddb/huntgroups
reading pairlist file /usr/local/etc/raddb/hints
  Module: Linked to module rlm_realm
  Module: Instantiating module "suffix" from file 
/usr/local/etc/raddb/modules/realm
   realm suffix {
         format = "suffix"
         delimiter = "@"
         ignore_default = no
         ignore_null = yes
   }
  Module: Instantiating module "ntdomain" from file 
/usr/local/etc/raddb/modules/realm
   realm ntdomain {
         format = "prefix"
         delimiter = "\"
         ignore_default = no
         ignore_null = yes
   }
  Module: Linked to module rlm_files
  Module: Instantiating module "files" from file 
/usr/local/etc/raddb/modules/files
   files {
         usersfile = "/usr/local/etc/raddb/users"
         acctusersfile = "/usr/local/etc/raddb/acct_users"
         preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
         compat = "no"
   }
reading pairlist file /usr/local/etc/raddb/users
reading pairlist file /usr/local/etc/raddb/acct_users
reading pairlist file /usr/local/etc/raddb/preproxy_users
  Module: Linked to module rlm_sql
  Module: Instantiating module "sql" from file /usr/local/etc/raddb/sql.conf
   sql {
         driver = "rlm_sql_mysql"
         server = "localhost"
         port = "3306"
         login = "raduser"
         password = "0000"
         radius_db = "raddb"
         read_groups = yes
         sqltrace = no
         sqltracefile = "/var/log/sqltrace.sql"
         readclients = yes
         deletestalesessions = yes
         num_sql_socks = 5
         lifetime = 0
         max_queries = 0
         sql_user_name = "%{User-Name}"
         default_user_profile = ""
         nas_query = "CALL load_clients()"
         authorize_check_query = "CALL authorize_check('%{SQL-User-Name}')"
         authorize_reply_query = "CALL authorize_reply('%{SQL-User-Name}')"
         authorize_group_check_query = "CALL 
authorize_group_check('%{Sql-Group}')"
         authorize_group_reply_query = "CALL 
authorize_group_reply('%{Sql-Group}')"
         accounting_onoff_query = "CALL accounting_on_off 
('%{Acct-Status-Type}' , '%{Called-Station-Id}')"
         accounting_update_query = "CALL accounting_update 
('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-
Input-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')"
         accounting_update_query_alt = "CALL accounting_update 
('%{Acct-Session-Id}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{A
cct-Input-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}')"
         accounting_start_query = "CALL accounting_start 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Call
ing-Station-Id}')"
         accounting_start_query_alt = "CALL accounting_start 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{
Calling-Station-Id}')"
         accounting_stop_query = "CALL accounting_stop 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-
Time}','%{Acct-Input-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')"
         accounting_stop_query_alt = "CALL accounting_stop 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Sess
ion-Time}','%{Acct-Input-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}')"
         group_membership_query = "CALL 
group_membership('%{SQL-User-Name}')"
         connect_failure_retry_delay = 60
         simul_count_query = "CALL simul_count('%{SQL-User-Name}')"
         simul_verify_query = ""
         postauth_query = ""
         safe-characters = 
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
   }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to raduser at localhost:3306/raddb
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is CALL load_clients()
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry nasname=192.168.0.4,shortname=HOME_AP,secret=0000
rlm_sql (sql): Adding client 192.168.0.4 (HOME_AP, server=<none>) to 
clients list
rlm_sql (sql): Released sql socket id: 4
  Module: Linked to module rlm_checkval
  Module: Instantiating module "checkval" from file 
/usr/local/etc/raddb/modules/checkval
   checkval {
         item-name = "Calling-Station-Id"
         check-name = "Calling-Station-Id"
         data-type = "string"
         notfound-reject = no
   }
rlm_checkval: Registered name Calling-Station-Id for attribute 31
  Module: Checking preacct {...} for more modules to load
  Module: Checking accounting {...} for more modules to load
  Module: Linked to module rlm_detail
  Module: Instantiating module "detail" from file 
/usr/local/etc/raddb/modules/detail
   detail {
         detailfile = 
"/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d"
         header = "%t"
         detailperm = 384
         dirperm = 493
         locking = no
         log_packet_header = no
         escape_filenames = no
   }
  Module: Instantiating module "datacounterdaily" from file 
/usr/local/etc/raddb/modules/datacounter_acct
   exec datacounterdaily {
         wait = no
         program = "/bin/echo hi"
         input_pairs = "request"
         shell_escape = yes
   }
  Module: Instantiating module "datacounterweekly" from file 
/usr/local/etc/raddb/modules/datacounter_acct
   exec datacounterweekly {
         wait = no
         program = "/bin/echo hi"
         input_pairs = "request"
         shell_escape = yes
   }
  Module: Instantiating module "datacountermonthly" from file 
/usr/local/etc/raddb/modules/datacounter_acct
   exec datacountermonthly {
         wait = no
         program = "/bin/echo hi"
         input_pairs = "request"
         shell_escape = yes
   }
  Module: Instantiating module "datacounterforever" from file 
/usr/local/etc/raddb/modules/datacounter_acct
   exec datacounterforever {
         wait = no
         program = "/usr/local/bin/bash 
/usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} 
%{request:Calling-Station-Id} %{request:NAS-IP-Ad
dress} %{request:Class} %{request:Acct-Status-Type}"
         input_pairs = "request"
         shell_escape = yes
   }
  Module: Linked to module rlm_attr_filter
  Module: Instantiating module "attr_filter.accounting_response" from 
file /usr/local/etc/raddb/modules/attr_filter
   attr_filter attr_filter.accounting_response {
         attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
         key = "%{User-Name}"
         relaxed = no
   }
reading pairlist file /usr/local/etc/raddb/attrs.accounting_response
  Module: Checking session {...} for more modules to load
  Module: Checking pre-proxy {...} for more modules to load
  Module: Instantiating module "attr_filter.pre-proxy" from file 
/usr/local/etc/raddb/modules/attr_filter
   attr_filter attr_filter.pre-proxy {
         attrsfile = "/usr/local/etc/raddb/attrs.pre-proxy"
         key = "%{Realm}"
         relaxed = no
   }
reading pairlist file /usr/local/etc/raddb/attrs.pre-proxy
  Module: Checking post-proxy {...} for more modules to load
  Module: Instantiating module "attr_filter.post-proxy" from file 
/usr/local/etc/raddb/modules/attr_filter
   attr_filter attr_filter.post-proxy {
         attrsfile = "/usr/local/etc/raddb/attrs"
         key = "%{Realm}"
         relaxed = no
   }
reading pairlist file /usr/local/etc/raddb/attrs
  Module: Checking post-auth {...} for more modules to load
  Module: Instantiating module "attr_filter.access_reject" from file 
/usr/local/etc/raddb/modules/attr_filter
   attr_filter attr_filter.access_reject {
         attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
         key = "%{User-Name}"
         relaxed = no
   }
reading pairlist file /usr/local/etc/raddb/attrs.access_reject
  } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
         type = "auth"
         ipaddr = 192.168.0.1
         port = 1812
}
listen {
         type = "acct"
         ipaddr = 192.168.0.1
         port = 1813
}
Listening on authentication address 192.168.0.1 port 1812
Listening on accounting address 192.168.0.1 port 1813
Listening on proxy address 192.168.0.1 port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=1, 
length=169
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 0x0269000e01616e6f6e796d6f7573
         Message-Authenticator = 0x6f32e006c6b27ccb58bc8bc78e2e3205
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 105 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
++policy redundant {
[sql]   expand: %{User-Name} -> anonymous
[sql] sql_set_user escaped user --> 'anonymous'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: CALL authorize_check('%{SQL-User-Name}') -> CALL 
authorize_check('anonymous')
[sql]   expand: CALL group_membership('%{SQL-User-Name}') -> CALL 
group_membership('anonymous')
rlm_sql (sql): Released sql socket id: 3
[sql] User anonymous not found
+++[sql] = notfound
++} # policy redundant = notfound
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] = noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 00-26-C6-72-D2-F8
rlm_checkval: Could not find attribute named Calling-Station-Id in check 
pairs
++[checkval] = notfound
++[expiration] = noop
++[logintime] = noop
[pap] WARNING! No "known good" password found for the user. 
Authentication may fail because of this.
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 1 to 192.168.0.4 port 58586
         EAP-Message = 0x016a00061520
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xb4e4aad6b48ebf06e52e0c33b4e5fbf2
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=2, 
length=229
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 
0x026a00381500160301002d01000029030142cf0aea5e88ab95c9cd6c305f61ffe159fd853caed9c07396f71d58332932f8000002000a0100
         State = 0xb4e4aad6b48ebf06e52e0c33b4e5fbf2
         Message-Authenticator = 0x6c0f70c11638cf5a316b0cd395bad365
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 106 length 56
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 002d], ClientHello
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 09d4], Certificate
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client 
certificate A
[ttls]     TLS_accept: Need to read more data: SSLv3 read client 
certificate A
In SSL Handshake Phase
In SSL Accept mode
[ttls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 2 to 192.168.0.4 port 58586
         EAP-Message = 
0x016b040015c000000a11160301002a020000260301cc599cac1c9998ef1bb2ef491c5ece75006101e1e0cce61e0cb713413823ce4a00000a0016030109d40b0009d000
09cd00051830820514308203fca003020102020101300d06092a864886f70d01010b0500308195310b3009060355040613025553310e300c060355040813055465786173310f300d06035504071306
41757374696e31263024060355040a131d4578616d706c6520436572746966696361746520417574686f726974793120301e06092a864886f70d01090116116365727473406578616d706c652e636f
6d311b301906035504031312667265657261646975732d74656d702d
         EAP-Message = 
0x6361301e170d3137303733303134313733355a170d3237303732383134313733355a308199310b3009060355040613025553310e300c06035504081305546578617331
0f300d0603550407130641757374696e31263024060355040a131d4578616d706c6520436572746966696361746520417574686f726974793120301e06092a864886f70d0109011611636572747340
6578616d706c652e636f6d311f301d06035504031316667265657261646975732d74656d702d73657276657230820122300d06092a864886f70d01010105000382010f003082010a0282010100ddd5
f66f6f917fc94c6c27ed5e2272405c8c673a3131263b560b62cf2cc1
         EAP-Message = 
0x06cc35c6aeb5564b2c8760930b7bb6a906ac59032fa6b94ed42b5f6e242f9af92dae3a3ce7b65141402fca918675d370c43784bb54f5ecfdc33b4c0e223ca4f70b0448
428aff1c9dfcd14c1e9e0a220d86707689a32850a7431ae40bb7fd975cd53efdd9b3f29799e3c5ee160f9d7c9ffc8afb6d17a775aff57cf7e90f96512fa13c32346ea12daddab9526cc1362b496e73
5e9b17957cf39a906c83fbe5ef4515bc5b9f69ce61ae2b90d5b4ce4765913cc02d5af73eb76949dc40c2bf5cf97e867b249fdafcfafef27e850e8cef9783a41d218ebc401ae2c24cc33a7b0173980a
470203010001a38201673082016330090603551d1304023000301106
         EAP-Message = 
0x096086480186f8420101040403020640303306096086480186f842010d042616244f70656e53534c2047656e6572617465642053657276657220436572746966696361
7465301d0603551d0e041604143bccd27850c43399eca9a78deeaece12a07db23f3081c20603551d230481ba3081b780141146326f07c5778d5978fe8a2de29dbefed4d028a1819ba4819830819531
0b3009060355040613025553310e300c060355040813055465786173310f300d0603550407130641757374696e31263024060355040a131d4578616d706c6520436572746966696361746520417574
686f726974793120301e06092a864886f70d01090116116365727473
         EAP-Message = 0x406578616d706c652e636f6d
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xb4e4aad6b58fbf06e52e0c33b4e5fbf2
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=3, 
length=179
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 0x026b00061500
         State = 0xb4e4aad6b58fbf06e52e0c33b4e5fbf2
         Message-Authenticator = 0x2bba9c81e5bad331d4791bcdb1ef4148
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 107 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 3 to 192.168.0.4 port 58586
         EAP-Message = 
0x016c040015c000000a11311b301906035504031312667265657261646975732d74656d702d6361820100301d0603551d250416301406082b0601050507030106082b06
010505080202300b0603551d0f0404030205a0300d06092a864886f70d01010b050003820101003147e47b5eb3976d2548a90a93dc0afe1183c5260799cca812e1ed0892f4bc59475cbd7bf0ee3e46
55c7afb725b7c1f679faeebbaecb2161463532a52c33637ddfee62e11aa141971967655f19adf91b4eb5b366cd42d264feae1d04d5cc5e68cfb962cfb552caf218a306218cc4a5ea5bc29401a72f5f
a658efe97156e4f35158a786f3817f7733b177ae0a2fcf1c08798833
         EAP-Message = 
0x2d103cb690f842a82b040588366a6755ed81de0a3e5cd12d1417be924d7e98fc2d6a9e4eb08107c25ac05902840ef7d7e5e8a0d2993b69ca0873dd149f5dcc23285521
dd028906a2c4e2ceef8c6b0fd43c1a9f55915b5a02b022100b90abc16125f5b091d626ec9c6b25f62f1a0004af308204ab30820393a003020102020100300d06092a864886f70d01010b0500308195
310b3009060355040613025553310e300c060355040813055465786173310f300d0603550407130641757374696e31263024060355040a131d4578616d706c65204365727469666963617465204175
74686f726974793120301e06092a864886f70d010901161163657274
         EAP-Message = 
0x73406578616d706c652e636f6d311b301906035504031312667265657261646975732d74656d702d6361301e170d3137303733303134313733355a170d323730373238
3134313733355a308195310b3009060355040613025553310e300c060355040813055465786173310f300d0603550407130641757374696e31263024060355040a131d4578616d706c652043657274
6966696361746520417574686f726974793120301e06092a864886f70d01090116116365727473406578616d706c652e636f6d311b301906035504031312667265657261646975732d74656d702d63
6130820122300d06092a864886f70d01010105000382010f00308201
         EAP-Message = 
0x0a0282010100d7ed60120b3344c7e822913cd56b439dbbdd3a830d921986cd2dc226fdaea6ad35812c32fe239692addb43f4f8fee8dd6b9b224610611b2dcf79e8febc
50d9daa743b19e6aa485fe488970e262761d5dbf12dfcb690bd65d9a04efd6d8d66f5f5a0985b355a562f8e20c896a912b0ef79754570acec27b656d62c646f5e09c2249f429a3b51566b70cf385b4
bf597d56d261c23149b9bdeacfe438524a33f7041c69bfa73d306e73d669856e9203a527a8c8de0f6a6311b07d0b08d6fbab65e2421f08425c88c8c9d1a8fe0f5c057780ad6128197a2281c9505c72
9e6baf6a1ca287e7fa5ec44940e1ba92019638e59efffa9ae07b75a7
         EAP-Message = 0xb4e4bf9850926106ed020301
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xb4e4aad6b688bf06e52e0c33b4e5fbf2
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=4, 
length=179
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 0x026c00061500
         State = 0xb4e4aad6b688bf06e52e0c33b4e5fbf2
         Message-Authenticator = 0xf6ea48856d66fad97dd4520f114c239a
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 108 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 4 to 192.168.0.4 port 58586
         EAP-Message = 
0x016d022f158000000a110001a38201023081ff301d0603551d0e041604141146326f07c5778d5978fe8a2de29dbefed4d0283081c20603551d230481ba3081b7801411
46326f07c5778d5978fe8a2de29dbefed4d028a1819ba48198308195310b3009060355040613025553310e300c060355040813055465786173310f300d0603550407130641757374696e3126302406
0355040a131d4578616d706c6520436572746966696361746520417574686f726974793120301e06092a864886f70d01090116116365727473406578616d706c652e636f6d311b3019060355040313
12667265657261646975732d74656d702d6361820100300c0603551d
         EAP-Message = 
0x13040530030101ff300b0603551d0f040403020106300d06092a864886f70d01010b0500038201010041e0078d94ddb8aa76266f78eff1bea1fe843f9051f25a7bda07
1af1c52660eb9bfbb42050e76f952465e5460c75c6fcf1f78139fc793b849d1ace4e08c64ebb670d52aa371b14825948cffbb62b99c464dd7ccb55f17ecbeacebd3ba2109423636b8a4e461a86cb43
01e143a27fdc25011ee292cfa7c7c6fa79cd996544d0f210866079b8cccfbaf3634fb4a7b57525e514da5dd63400aeeb837d2e09ef7f917ad5a2a64ba8a28b3560a4c7fe17dadf9d4f9c98a9acc312
8b6170ff025191886951e17b9d50627c50c2c43d8073b35b57b52ec8
         EAP-Message = 
0x37f0cff5a87110fc1519e1d7fd66eb0c5f6419ca6e91974a3499bf546ca486c8765b459d018728e245bf900116030100040e000000
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xb4e4aad6b789bf06e52e0c33b4e5fbf2
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=5, 
length=499
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 
0x026d014415001603010106100001020100a2567e8f00963ec0e82064a375ecb2492d3a40cdb21fcd3cf802f5a7a9a8b01d927f0182e0869855b8dae16e3d2f14e9045f
4b822a5d8732914005ec5daf364d3ef966301b46153fb8a0a7c477a99bab945a8baaec315e245bd8a9bc84a239707aa56b3b3e6baaab8b6fa509250fb1311bd2b7600014d06269be9261ce9ae2d55c
35abfded59288cfecc054b80d4e875eeaf02278da4c3fc55667660ca0e26a94e043bdb958e927a7fd02e739107de0851317eae4e88e969c28af29c7ff588c1c156ba6f51b711fab2859821e92fff8b
367c750c2e892d92689b0311858333b347e1ab4f4f1e9e57898f4a4d
         EAP-Message = 
0x238051ca5fd5cc9d2a5659d11575a3b0112a090a1403010001011603010028ef7a4920c4c3c713f84b77cfa15822957cdc6e94cca75134d9c548f3784bab6d1dc22009
4bb47b2a
         State = 0xb4e4aad6b789bf06e52e0c33b4e5fbf2
         Message-Authenticator = 0x90611aec292e409758bab4236eb791e9
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 109 length 253
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls]     TLS_accept: SSLv3 read certificate verify A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established
[ttls] eaptls_process returned 13
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 5 to 192.168.0.4 port 58586
         EAP-Message = 
0x016e003d158000000033140301000101160301002893952457d51f458aa7d6a68db5db3edb2cbcc07daff3cada6eaca13f3465ff559ac90b8f7b86c912
         Message-Authenticator = 0x00000000000000000000000000000000
         State = 0xb4e4aad6b08abf06e52e0c33b4e5fbf2
Finished request 4.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 192.168.0.4 port 58586, id=6, 
length=240
         User-Name = "anonymous"
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         EAP-Message = 
0x026e0043150017030100389be64fff33167a8a251fdfb1a94fdaeffc8c379238e4f891c7d403f0af446b92d0ee78a4ee219f9cc9f89f5c04847513f68b63e8ea07aea5
         State = 0xb4e4aad6b08abf06e52e0c33b4e5fbf2
         Message-Authenticator = 0x0e91867bde1f5e4cb7ab6fcadb7c193e
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "anonymous", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "anonymous", skipping NULL due to config.
++[ntdomain] = noop
[eap] EAP packet type response id 110 length 67
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7
[ttls] Done initial handshake
[ttls] eaptls_process returned 7
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
         User-Name = "scilek"
         User-Password = "0000"
         FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
         User-Name = "scilek"
         User-Password = "0000"
         FreeRADIUS-Proxied-To = 127.0.0.1
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         Framed-MTU = 1400
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         NAS-IP-Address = 192.168.0.4
server  {
# Executing section authorize from file 
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[digest] = noop
[suffix] No '@' in User-Name = "scilek", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "scilek", skipping NULL due to config.
++[ntdomain] = noop
[eap] No EAP-Message, not doing EAP
++[eap] = noop
++[files] = noop
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: CALL authorize_check('%{SQL-User-Name}') -> CALL 
authorize_check('scilek')
[sql] User found in radcheck table
[sql]   expand: CALL authorize_reply('%{SQL-User-Name}') -> CALL 
authorize_reply('scilek')
[sql]   expand: CALL group_membership('%{SQL-User-Name}') -> CALL 
group_membership('scilek')
rlm_sql (sql): Released sql socket id: 2
+++[sql] = ok
++} # policy redundant = ok
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[weekly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[monthly] = noop
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[forever] = noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 00-26-C6-72-D2-F8
rlm_checkval: Could not find attribute named Calling-Station-Id in check 
pairs
++[checkval] = notfound
++[expiration] = noop
++[logintime] = noop
++[pap] = updated
+} # group authorize = updated
Found Auth-Type = PAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group PAP {
[pap] login attempt with password "0000"
[pap] Using clear text password "0000"
[pap] User authenticated successfully
++[pap] = ok
+} # group PAP = ok
# Executing section session from file 
/usr/local/etc/raddb/sites-enabled/default
+group session {
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: CALL simul_count('%{SQL-User-Name}') -> CALL 
simul_count('scilek')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
+++[sql] = ok
++} # policy redundant = ok
+} # group session = ok
         expand:  ->
Login OK: [scilek] (from client HOME_AP port 0 cli 00-26-C6-72-D2-F8 via 
TLS tunnel)
# Executing section post-auth from file 
/usr/local/etc/raddb/sites-enabled/default
+group post-auth {
++update reply {
         expand: %{User-Name} -> scilek
++} # update reply = noop
Warning: Using a password on the command line interface can be insecure.
Exec output:
[exec] Exec: program returned: 0
++[exec] = ok
+} # group post-auth = ok
} # server
[ttls] Got tunneled reply code Access-Accept
         Class = 0x5f7363696c656b
         Idle-Timeout = 120
         Acct-Interim-Interval = 600
         Exec-Program-Wait = "/usr/local/bin/bash 
/usr/local/etc/raddb/scripts/datacounter_auth.sh scilek"
         User-Name = "scilek"
[ttls] Got tunneled Access-Accept
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
         expand:  ->
Login OK: [anonymous] (from client HOME_AP port 0 cli 00-26-C6-72-D2-F8)
# Executing section post-auth from file 
/usr/local/etc/raddb/sites-enabled/default
+group post-auth {
++update reply {
         expand: %{User-Name} -> anonymous
++} # update reply = noop
Warning: Using a password on the command line interface can be insecure.
Exec output:
[exec] Exec: program returned: 0
++[exec] = ok
+} # group post-auth = ok
Sending Access-Accept of id 6 to 192.168.0.4 port 58586
         Class = 0x5f7363696c656b
         Idle-Timeout = 120
         Acct-Interim-Interval = 600
         User-Name = "scilek"
         MS-MPPE-Recv-Key = 
0x2a32e67944b4e75f0a9fcfd85157d957a8b21eb8d6325eb41f90fc3a2017c9be
         MS-MPPE-Send-Key = 
0x44447512273cc60492a384b34b8feeac525cb064d850920ddf10223b686c0c4e
         EAP-Message = 0x036e0004
         Message-Authenticator = 0x00000000000000000000000000000000
Finished request 5.
Going to the next request
Waking up in 4.5 seconds.
rad_recv: Accounting-Request packet from host 192.168.0.4 port 44196, 
id=7, length=172
         Acct-Session-Id = "59C5EC66-00000000"
         Acct-Status-Type = Start
         Acct-Authentic = RADIUS
         User-Name = "scilek"
         Framed-IP-Address = 192.168.1.113
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         Class = 0x5f7363696c656b
# Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/default
+group preacct {
++[preprocess] = ok
++update request {
         expand: %{Acct-Session-Time} ->
         ... expanding second conditional
         expand: %{Acct-Delay-Time} ->
         ... expanding second conditional
         expand:  %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0} ->  1506143408 - 0 - 0
         expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0}} -> 1506143408
++} # update request = noop
[suffix] No '@' in User-Name = "scilek", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "scilek", skipping NULL due to config.
++[ntdomain] = noop
++[files] = noop
+} # group preacct = ok
# Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/default
+group accounting {
++? if (Acct-Session-Time == 0)
     (Attribute Acct-Session-Time was not found)
? Evaluating (Acct-Session-Time == 0) -> FALSE
++? if (Acct-Session-Time == 0) -> FALSE
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.4
[detail]        expand: 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
-> /var/log/radacct/192.168.0.4/detail_2017_0
9_23
[detail] 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
[detail]        expand: %t -> Sat Sep 23 08:10:08 2017
++[detail] = ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] = noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update)) -> FALSE
++[unix] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: CALL accounting_start 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Class}','%{NAS-IP-Address}','%{Called-Station-Id}','%{Calling-Station-Id}')
-> CALL accounting_start 
('59C5EC66-00000000','scilek','0x5f7363696c656b','192.168.0.4','82-2A-A8-AD-1E-F9:SCILEK.NET','00-26-C6-72-D2-F8')
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql (sql): Released sql socket id: 0
+++[sql] = ok
++} # policy redundant = ok
++[exec] = noop
[attr_filter.accounting_response]       expand: %{User-Name} -> scilek
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 7 to 192.168.0.4 port 44196
Finished request 6.
Cleaning up request 6 ID 7 with timestamp +13
Going to the next request
Waking up in 4.2 seconds.
Cleaning up request 0 ID 1 with timestamp +12
Cleaning up request 1 ID 2 with timestamp +12
Cleaning up request 2 ID 3 with timestamp +12
Cleaning up request 3 ID 4 with timestamp +12
Cleaning up request 4 ID 5 with timestamp +12
Waking up in 0.1 seconds.
Cleaning up request 5 ID 6 with timestamp +12
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.0.4 port 44196, 
id=8, length=214
         Acct-Session-Id = "59C5EC66-00000000"
         Acct-Status-Type = Stop
         Acct-Authentic = RADIUS
         User-Name = "scilek"
         Framed-IP-Address = 192.168.1.113
         NAS-Identifier = "802aa8ac1ef9"
         NAS-Port = 0
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Calling-Station-Id = "00-26-C6-72-D2-F8"
         NAS-Port-Type = Wireless-802.11
         Connect-Info = "CONNECT 0Mbps 802.11b"
         Class = 0x5f7363696c656b
         Acct-Session-Time = 62
         Acct-Input-Packets = 2198
         Acct-Output-Packets = 1981
         Acct-Input-Octets = 2995341
         Acct-Output-Octets = 2870213
         Event-Timestamp = "Sep 23 2017 08:11:11 +03"
         Acct-Terminate-Cause = User-Request
# Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/default
+group preacct {
++[preprocess] = ok
++update request {
         expand: %{Acct-Session-Time} -> 62
         expand: %{Acct-Delay-Time} ->
         ... expanding second conditional
         expand:  %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0} ->  1506143469 - 62 - 0
         expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0}} -> 1506143407
++} # update request = noop
[suffix] No '@' in User-Name = "scilek", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '\' in User-Name = "scilek", skipping NULL due to config.
++[ntdomain] = noop
++[files] = noop
+} # group preacct = ok
# Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/default
+group accounting {
++? if (Acct-Session-Time == 0)
? Evaluating (Acct-Session-Time == 0) -> FALSE
++? if (Acct-Session-Time == 0) -> FALSE
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.4
[detail]        expand: 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
-> /var/log/radacct/192.168.0.4/detail_2017_0
9_23
[detail] 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
[detail]        expand: %t -> Sat Sep 23 08:11:09 2017
++[detail] = ok
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=scilek, New Counter=62.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[daily] = ok
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=scilek, New Counter=62.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[weekly] = ok
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=scilek, New Counter=62.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[monthly] = ok
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=scilek, New Counter=62.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[forever] = ok
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
?? Skipping (request:Acct-Status-Type == Interim-Update)
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update)) -> TRUE
++if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == 
Interim-Update)) {
+++[datacounterdaily] = ok
+++[datacounterweekly] = ok
+++[datacountermonthly] = ok
[datacounterforever]    expand: %{request:User-Name} -> scilek
[datacounterforever]    expand: %{request:Calling-Station-Id} -> 
00-26-C6-72-D2-F8
[datacounterforever]    expand: %{request:NAS-IP-Address} -> 192.168.0.4
[datacounterforever]    expand: %{request:Class} -> 0x5f7363696c656b
[datacounterforever]    expand: %{request:Acct-Status-Type} -> Stop
+++[datacounterforever] = ok
++} # if ((request:Acct-Status-Type == Stop) || 
(request:Acct-Status-Type == Interim-Update)) = ok
++[unix] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: CALL accounting_stop 
('%{Acct-Session-Id}','%{SQL-User-Name}','%{Called-Station-Id}','%{Calling-Station-Id}','%{Acct-Session-Time}','%{Acct-In
put-Octets}','%{Acct-Input-Gigawords}','%{Acct-Output-Octets}','%{Acct-Output-Gigawords}','%{Acct-Terminate-Cause}') 
-> CALL accounting_stop ('59C5EC66-000000
00','scilek','82-2A-A8-AD-1E-F9:SCILEK.NET','00-26-C6-72-D2-F8','62','2995341','','2870213','','User-Request')
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Released sql socket id: 4
+++[sql] = ok
++} # policy redundant = ok
++[exec] = noop
[attr_filter.accounting_response]       expand: %{User-Name} -> scilek
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 8 to 192.168.0.4 port 44196
Finished request 7.
Cleaning up request 7 ID 8 with timestamp +74
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.0.4 port 44196, 
id=0, length=82
         Acct-Status-Type = Accounting-On
         Acct-Authentic = RADIUS
         NAS-Identifier = "802aa8ac1ef9"
         Called-Station-Id = "82-2A-A8-AD-1E-F9:SCILEK.NET"
         Acct-Terminate-Cause = NAS-Reboot
# Executing section preacct from file 
/usr/local/etc/raddb/sites-enabled/default
+group preacct {
++[preprocess] = ok
++update request {
         expand: %{Acct-Session-Time} ->
         ... expanding second conditional
         expand: %{Acct-Delay-Time} ->
         ... expanding second conditional
         expand:  %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0} ->  1506143521 - 0 - 0
         expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - 
%{%{Acct-Delay-Time}:-0}} -> 1506143521
++} # update request = noop
[suffix] Proxy reply, or no User-Name.  Ignoring.
++[suffix] = ok
[ntdomain] Proxy reply, or no User-Name.  Ignoring.
++[ntdomain] = ok
++[files] = noop
+} # group preacct = ok
# Executing section accounting from file 
/usr/local/etc/raddb/sites-enabled/default
+group accounting {
++? if (Acct-Session-Time == 0)
     (Attribute Acct-Session-Time was not found)
? Evaluating (Acct-Session-Time == 0) -> FALSE
++? if (Acct-Session-Time == 0) -> FALSE
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.0.4
[detail]        expand: 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
-> /var/log/radacct/192.168.0.4/detail_2017_0
9_23
[detail] 
/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail_%Y_%m_%d 
expands to /var/log/radacct/192.168.0.4/detail_2017_09_23
[detail]        expand: %t -> Sat Sep 23 08:12:01 2017
++[detail] = ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] = noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type 
== Interim-Update)) -> FALSE
++[unix] = noop
++policy redundant {
[sql] Received Acct On/Off packet
[sql]   expand: CALL accounting_on_off ('%{Acct-Status-Type}' , 
'%{Called-Station-Id}') -> CALL accounting_on_off ('Accounting-On' , 
'82-2A-A8-AD-1E-F9:SCILEK
.NET')
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_mysql: MYSQL check_error: 1305 received
[sql] Couldn't update SQL accounting for Acct On/Off packet - PROCEDURE 
raddb.accounting_on_off does not exist
rlm_sql_mysql: MYSQL check_error: 1305 received
rlm_sql_mysql: Cannot store result
rlm_sql_mysql: MySQL error 'PROCEDURE raddb.accounting_on_off does not 
exist'
rlm_sql (sql): Released sql socket id: 3
+++[sql] = fail
++} # policy redundant = fail
+} # group accounting = fail
Finished request 8.
Cleaning up request 8 ID 0 with timestamp +126
Going to the next request
Ready to process requests.



---
This email has been checked for viruses by Avast antivirus software.
https://www.avast.com/antivirus




More information about the Freeradius-Users mailing list