[2.3.2-RELEASE][root@pfsense-router.scilek.net]/root: /usr/local/sbin/rad
raddebug* radiusd*  radmin*   radvd*    radvdump* radwatch*
[2.3.2-RELEASE][root@pfsense-router.scilek.net]/root: /usr/local/sbin/radiusd -X
radiusd: FreeRADIUS Version 2.2.9, for host amd64-portbld-freebsd10.3, built on Sep 27 2016 at 16:07:13
Copyright (C) 1999-2015 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License.
For more information about these matters, see the file named COPYRIGHT.
Starting - reading configuration files ...
including configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/clients.conf
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/always
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
including configuration file /usr/local/etc/raddb/modules/cache
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/cui
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/detail.example.com
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/dhcp_sqlippool
including configuration file /usr/local/etc/raddb/sql/mysql/ippool-dhcp.conf
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/dynamic_clients
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/exec
including configuration file /usr/local/etc/raddb/modules/expiration
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/files
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/krb5
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/otp
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/ntlm_auth
including configuration file /usr/local/etc/raddb/modules/opendirectory
including configuration file /usr/local/etc/raddb/modules/pam
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/perl
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/preprocess
including configuration file /usr/local/etc/raddb/modules/radrelay
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/redis
including configuration file /usr/local/etc/raddb/modules/rediswho
including configuration file /usr/local/etc/raddb/modules/replicate
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/smsotp
including configuration file /usr/local/etc/raddb/modules/soh
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/modules/motp
including configuration file /usr/local/etc/raddb/modules/datacounter_acct
including configuration file /usr/local/etc/raddb/eap.conf
including configuration file /usr/local/etc/raddb/sql.conf
including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf
including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf
including configuration file /usr/local/etc/raddb/sql/mysql/counter.conf
including configuration file /usr/local/etc/raddb/policy.conf
including files in directory /usr/local/etc/raddb/sites-enabled/
including configuration file /usr/local/etc/raddb/sites-enabled/default
main {
        allow_core_dumps = no
}
including dictionary file /usr/local/etc/raddb/dictionary
main {
        name = "radiusd"
        prefix = "/usr/local"
        localstatedir = "/var"
        sbindir = "/usr/local/sbin"
        logdir = "/var/log"
        run_dir = "/var/run"
        radacctdir = "/var/log/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 1024
        pidfile = "/var/run/radiusd.pid"
        checkrad = "/usr/local/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = yes
        auth_badpass = no
        auth_goodpass = no
        msg_badpass = ""
        msg_goodpass = ""
 }
 security {
        max_attributes = 200
        reject_delay = 3
        status_server = no
        allow_vulnerable_openssl = no
 }
}
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Loading Clients ####
 client HOME_AP {
        ipaddr = 192.168.2.3
        require_message_authenticator = yes
        secret = "0000"
        shortname = "HOME_AP"
        nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
        timeout = 10
  }
 Module: Linked to module rlm_expr
 Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr
 Module: Linked to module rlm_counter
 Module: Instantiating module "daily" from file /usr/local/etc/raddb/modules/counter
  counter daily {
        filename = "/var/log/radacct/timecounter/db.daily"
        key = "User-Name"
        reset = "daily"
        count-attribute = "Acct-Session-Time"
        counter-name = "Daily-Session-Time"
        check-name = "Max-Daily-Session"
        reply-name = "Session-Timeout"
        cache-size = 5000
  }
rlm_counter: Counter attribute Daily-Session-Time is number 11273
rlm_counter: Current Time: 1486089485 [2017-02-03 05:38:05], Next reset 1486155600 [2017-02-04 00:00:00]
 Module: Instantiating module "weekly" from file /usr/local/etc/raddb/modules/counter
  counter weekly {
        filename = "/var/log/radacct/timecounter/db.weekly"
        key = "User-Name"
        reset = "weekly"
        count-attribute = "Acct-Session-Time"
        counter-name = "Weekly-Session-Time"
        check-name = "Max-Weekly-Session"
        reply-name = "Session-Timeout"
        cache-size = 5000
  }
rlm_counter: Counter attribute Weekly-Session-Time is number 11275
rlm_counter: Current Time: 1486089485 [2017-02-03 05:38:05], Next reset 1486242000 [2017-02-05 00:00:00]
 Module: Instantiating module "monthly" from file /usr/local/etc/raddb/modules/counter
  counter monthly {
        filename = "/var/log/radacct/timecounter/db.monthly"
        key = "User-Name"
        reset = "monthly"
        count-attribute = "Acct-Session-Time"
        counter-name = "Monthly-Session-Time"
        check-name = "Max-Monthly-Session"
        reply-name = "Session-Timeout"
        cache-size = 5000
  }
rlm_counter: Counter attribute Monthly-Session-Time is number 11277
rlm_counter: Current Time: 1486089485 [2017-02-03 05:38:05], Next reset 1488315600 [2017-03-01 00:00:00]
 Module: Instantiating module "forever" from file /usr/local/etc/raddb/modules/counter
  counter forever {
        filename = "/var/log/radacct/timecounter/db.forever"
        key = "User-Name"
        reset = "never"
        count-attribute = "Acct-Session-Time"
        counter-name = "Forever-Session-Time"
        check-name = "Max-Forever-Session"
        reply-name = "Session-Timeout"
        cache-size = 5000
  }
rlm_counter: Counter attribute Forever-Session-Time is number 11279
rlm_counter: Current Time: 1486089485 [2017-02-03 05:38:05], Next reset 0 [2017-02-03 05:00:00]
 Module: Linked to module rlm_expiration
 Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration
  expiration {
        reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime
  logintime {
        reply-message = "You are calling outside your allowed timespan  "
        minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server { # from file /usr/local/etc/raddb/radiusd.conf
 modules {
  Module: Creating Auth-Type = MOTP
  Module: Creating Auth-Type = digest
  Module: Creating Autz-Type = Status-Server
  Module: Creating Acct-Type = Status-Server
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap
  pap {
        encryption_scheme = "auto"
        auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap
 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} %{reply: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.pem"
        certificate_file = "/usr/local/etc/raddb/certs/server.pem"
        CA_file = "/usr/local/etc/raddb/certs/ca.pem"
        private_key_password = "whatever"
        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 = yes
        lifetime = 24
        max_entries = 1024
    }
    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 = no
        sqltrace = no
        sqltracefile = "/var/log/sqltrace.sql"
        readclients = no
        deletestalesessions = yes
        num_sql_socks = 32
        lifetime = 0
        max_queries = 0
        sql_user_name = "%{User-Name}"
        default_user_profile = ""
        nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
        authorize_check_query = "SELECT id, username, attribute, value, op           FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
        authorize_reply_query = "SELECT id, username, attribute, value, op           FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id"
        authorize_group_check_query = "SELECT id, groupname, attribute,           Value, op           FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'          ORDER BY id"
        authorize_group_reply_query = "SELECT id, groupname, attribute,           value, op           FROM radgroupreply           WHERE groupname = '%{Sql-Group}'          ORDER BY id"
        accounting_onoff_query = "          UPDATE radacct           SET              acctstoptime       =  '%S',              acctsessiontime    =  unix_timestamp('%S') -                                   unix_timestamp(acctstarttime),              acctterminatecause =  '%{Acct-Terminate-Cause}',              acctstopdelay      =  %{%{Acct-Dlay-Time}:-0}           WHERE acctstoptime IS NULL           AND nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <= '%S'"
        accounting_update_query = "           UPDATE radacct           SET              framedipaddress = '%{Framed-IP-Address}',              acctsessiontime     = '%{%{Act-Session-Time}:-0}',              acctinputoctets     = '%{%{Acct-Input-Gigawords}:-0}'  << 32 |                                    '%{%{Acct-Input-Octets}:-0}',             acctoutputoctets    = '%{%{Acct-Output-Gigawords}:-0}' << 32 |                                    '%{%{Acct-Output-Octets}:-0}'           WHERE acctsessionid = '%{Acct-Sssion-Id}'           AND username        = '%{SQL-User-Name}'           AND nasipaddress    = '%{NAS-IP-Address}'"
        accounting_update_query_alt = "           INSERT INTO radacct             (acctsessionid,    acctuniqueid,      username,              realm,            nasipaddres,      nasportid,              nasporttype,      acctstarttime,     acctsessiontime,              acctauthentic,    connectinfo_start, acctinputoctets,              acctoututoctets, calledstationid,   callingstationid,              servicetype,      framedprotocol,    framedipaddress,              acctstartdelay,   xascendsessionsvrkey)          VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',             '%{NAS-Port-Type}',              DATE_SUB('%S',                       INTERVAL (%{%{Acct-Session-Time}:-0} +                                 %{%{Acct-Delay-Time}:-}) SECOND),                       '%{%{Acct-Session-Time}:-0}',              '%{Acct-Authentic}', '',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |              '%{%Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Calling-Sation-Id}',              '%{Service-Type}', '%{Framed-Protocol}',              '%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query = "           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-Usr-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}',             '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query_alt = "           UPDATE radacct SET              acctstarttime     = '%S',              acctstartdelay    = '%{%{Acct-Delay-Time}:-0}',             connectinfo_start = '%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'           AND username         = '%{SQL-User-Name}'           AND nasipadress     = '%{NAS-IP-Address}'"
        accounting_stop_query = "           UPDATE radacct SET              acctstoptime       = '%S',              acctsessiontime    = '%{%{Acct-Session-Time}:-0}',             acctinputoctets    = '%{%{Acct-Input-Gigawords}:-0}' << 32 |                                   '%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   = '%{%{Act-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 usrname          = '%{SQL-User-Name}'           AND nasipaddress      = '%{NAS-IP-Address}'"
        accounting_stop_query_alt = "           INSERT INTO radacct             (acctsessionid, acctuniqueid, username,              realm, nasipaddress, nasportid,             nasporttype, acctstarttime, acctstoptime,              acctsessiontime, acctauthentic, connectinfo_start,              connectinfo_stop, acctinputoctets, acctoutputoctts,              calledstationid, callingstationid, acctterminatecause,              servicetype, framedprotocol, framedipaddress,              acctstartdelay, acctstopdela)           VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Por}',              '%{NAS-Port-Type}',              DATE_SUB('%S',                  INTERVAL (%{%{Acct-Session-Time}:-0} +                  %{%{Acct-Delay-Time}:-0}) SECOND),             '%S', '%{%{Acct-Session-Time}:-0}', '%{Acct-Authentic}', '',              '%{Connect-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |              %{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32 |              '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}', '%{Callig-Station-Id}',              '%{Acct-Terminate-Cause}',              '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',              '0', '%{%{Acct-Delay-Time:-0}')"
        group_membership_query = "SELECT groupname           FROM radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER BY priority"
        connect_failure_retry_delay = 60
        simul_count_query = "SELECT COUNT(*)                              FROM radacct                              WHERE username = '%{SQL-User-Name}'                             AND acctstoptime IS NULL"
        simul_verify_query = "SELECT radacctid, acctsessionid, username,                                nasipaddress, nasportid, framedipaddress,                               callingstationid, framedprotocol                                FROM radacct                                WHERE username = '%{SQL-User-Name}'                               AND acctstoptime IS NULL"
        postauth_query = "INSERT INTO radpostauth                           (username, pass, reply, authdate)                           VALUES (                           '{User-Name}',                           '%{%{User-Password}:-%{Chap-Password}}',                           '%{reply:Packet-Type}', '%S')"
        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@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): starting 5
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5
rlm_sql (sql): Connected new DB handle, #5
rlm_sql (sql): starting 6
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql (sql): Connected new DB handle, #6
rlm_sql (sql): starting 7
rlm_sql (sql): Attempting to connect rlm_sql_mysql #7
rlm_sql_mysql: Starting connect to MySQL server for #7
rlm_sql (sql): Connected new DB handle, #7
rlm_sql (sql): starting 8
rlm_sql (sql): Attempting to connect rlm_sql_mysql #8
rlm_sql_mysql: Starting connect to MySQL server for #8
rlm_sql (sql): Connected new DB handle, #8
rlm_sql (sql): starting 9
rlm_sql (sql): Attempting to connect rlm_sql_mysql #9
rlm_sql_mysql: Starting connect to MySQL server for #9
rlm_sql (sql): Connected new DB handle, #9
rlm_sql (sql): starting 10
rlm_sql (sql): Attempting to connect rlm_sql_mysql #10
rlm_sql_mysql: Starting connect to MySQL server for #10
rlm_sql (sql): Connected new DB handle, #10
rlm_sql (sql): starting 11
rlm_sql (sql): Attempting to connect rlm_sql_mysql #11
rlm_sql_mysql: Starting connect to MySQL server for #11
rlm_sql (sql): Connected new DB handle, #11
rlm_sql (sql): starting 12
rlm_sql (sql): Attempting to connect rlm_sql_mysql #12
rlm_sql_mysql: Starting connect to MySQL server for #12
rlm_sql (sql): Connected new DB handle, #12
rlm_sql (sql): starting 13
rlm_sql (sql): Attempting to connect rlm_sql_mysql #13
rlm_sql_mysql: Starting connect to MySQL server for #13
rlm_sql (sql): Connected new DB handle, #13
rlm_sql (sql): starting 14
rlm_sql (sql): Attempting to connect rlm_sql_mysql #14
rlm_sql_mysql: Starting connect to MySQL server for #14
rlm_sql (sql): Connected new DB handle, #14
rlm_sql (sql): starting 15
rlm_sql (sql): Attempting to connect rlm_sql_mysql #15
rlm_sql_mysql: Starting connect to MySQL server for #15
rlm_sql (sql): Connected new DB handle, #15
rlm_sql (sql): starting 16
rlm_sql (sql): Attempting to connect rlm_sql_mysql #16
rlm_sql_mysql: Starting connect to MySQL server for #16
rlm_sql (sql): Connected new DB handle, #16
rlm_sql (sql): starting 17
rlm_sql (sql): Attempting to connect rlm_sql_mysql #17
rlm_sql_mysql: Starting connect to MySQL server for #17
rlm_sql (sql): Connected new DB handle, #17
rlm_sql (sql): starting 18
rlm_sql (sql): Attempting to connect rlm_sql_mysql #18
rlm_sql_mysql: Starting connect to MySQL server for #18
rlm_sql (sql): Connected new DB handle, #18
rlm_sql (sql): starting 19
rlm_sql (sql): Attempting to connect rlm_sql_mysql #19
rlm_sql_mysql: Starting connect to MySQL server for #19
rlm_sql (sql): Connected new DB handle, #19
rlm_sql (sql): starting 20
rlm_sql (sql): Attempting to connect rlm_sql_mysql #20
rlm_sql_mysql: Starting connect to MySQL server for #20
rlm_sql (sql): Connected new DB handle, #20
rlm_sql (sql): starting 21
rlm_sql (sql): Attempting to connect rlm_sql_mysql #21
rlm_sql_mysql: Starting connect to MySQL server for #21
rlm_sql (sql): Connected new DB handle, #21
rlm_sql (sql): starting 22
rlm_sql (sql): Attempting to connect rlm_sql_mysql #22
rlm_sql_mysql: Starting connect to MySQL server for #22
rlm_sql (sql): Connected new DB handle, #22
rlm_sql (sql): starting 23
rlm_sql (sql): Attempting to connect rlm_sql_mysql #23
rlm_sql_mysql: Starting connect to MySQL server for #23
rlm_sql (sql): Connected new DB handle, #23
rlm_sql (sql): starting 24
rlm_sql (sql): Attempting to connect rlm_sql_mysql #24
rlm_sql_mysql: Starting connect to MySQL server for #24
rlm_sql (sql): Connected new DB handle, #24
rlm_sql (sql): starting 25
rlm_sql (sql): Attempting to connect rlm_sql_mysql #25
rlm_sql_mysql: Starting connect to MySQL server for #25
rlm_sql (sql): Connected new DB handle, #25
rlm_sql (sql): starting 26
rlm_sql (sql): Attempting to connect rlm_sql_mysql #26
rlm_sql_mysql: Starting connect to MySQL server for #26
rlm_sql (sql): Connected new DB handle, #26
rlm_sql (sql): starting 27
rlm_sql (sql): Attempting to connect rlm_sql_mysql #27
rlm_sql_mysql: Starting connect to MySQL server for #27
rlm_sql (sql): Connected new DB handle, #27
rlm_sql (sql): starting 28
rlm_sql (sql): Attempting to connect rlm_sql_mysql #28
rlm_sql_mysql: Starting connect to MySQL server for #28
rlm_sql (sql): Connected new DB handle, #28
rlm_sql (sql): starting 29
rlm_sql (sql): Attempting to connect rlm_sql_mysql #29
rlm_sql_mysql: Starting connect to MySQL server for #29
rlm_sql (sql): Connected new DB handle, #29
rlm_sql (sql): starting 30
rlm_sql (sql): Attempting to connect rlm_sql_mysql #30
rlm_sql_mysql: Starting connect to MySQL server for #30
rlm_sql (sql): Connected new DB handle, #30
rlm_sql (sql): starting 31
rlm_sql (sql): Attempting to connect rlm_sql_mysql #31
rlm_sql_mysql: Starting connect to MySQL server for #31
rlm_sql (sql): Connected new DB handle, #31
 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: Linked to module rlm_acct_unique
 Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique
  acct_unique {
        key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
  }
 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 = yes
        program = "/bin/sh /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} daily %{request:Acct-Input-Octets} %{request:Acct-Output-Octets} %{request:cct-Status-Type} %{request:Acct-Session-Id}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacounterweekly" from file /usr/local/etc/raddb/modules/datacounter_acct
  exec datacounterweekly {
        wait = yes
        program = "/bin/sh /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} weekly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets} %{requestAcct-Status-Type} %{request:Acct-Session-Id}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacountermonthly" from file /usr/local/etc/raddb/modules/datacounter_acct
  exec datacountermonthly {
        wait = yes
        program = "/bin/sh /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} monthly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets} %{reques:Acct-Status-Type} %{request:Acct-Session-Id}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Instantiating module "datacounterforever" from file /usr/local/etc/raddb/modules/datacounter_acct
  exec datacounterforever {
        wait = yes
        program = "/bin/sh /usr/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} forever %{request:Acct-Input-Octets} %{request:Acct-Output-Octets} %{reques:Acct-Status-Type} %{request:Acct-Session-Id}"
        input_pairs = "request"
        shell_escape = yes
  }
 Module: Linked to module rlm_radutmp
 Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp
  radutmp {
        filename = "/var/log/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        perm = 384
        callerid = 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.2.1
        port = 1812
}
listen {
        type = "acct"
        ipaddr = 192.168.2.1
        port = 1813
}
Listening on authentication address 192.168.2.1 port 1812
Listening on accounting address 192.168.2.1 port 1813
Listening on proxy address 192.168.2.1 port 1814
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.2.3 port 50336, id=0, length=82
        Acct-Status-Type = Accounting-On
        Acct-Authentic = RADIUS
        NAS-Identifier = "802aa8ac1ef9"
        Called-Station-Id = "80-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} ->  1486089614 - 0 - 0
        expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1486089614
++} # update request = noop
[acct_unique] WARNING: Attribute NAS-Port was not found in request, unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute Acct-Session-Id was not found in request, unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute User-Name was not found in request, unique ID MAY be inconsistent
[acct_unique] Hashing ',NAS-Identifier = "802aa8ac1ef9",NAS-IP-Address = 192.168.2.3,,'
[acct_unique] Acct-Unique-Session-ID = "2166b6af02edae53".
++[acct_unique] = ok
[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 {
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.2.3
[detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.2.3/detail-20170203
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.2.3/detail-20170203
[detail]        expand: %t -> Fri Feb  3 05:40:14 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
[radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
rlm_radutmp: NAS HOME_AP restarted (Accounting-On packet seen)
++[radutmp] = ok
++policy redundant {
[sql] Received Acct On/Off packet
[sql]   expand: %{Acct-Delay-Time} ->
[sql]   ... expanding second conditional
[sql]   expand:           UPDATE radacct           SET              acctstoptime       =  '%S',              acctsessiontime    =  unix_timestamp('%S') -                                    unix_timestamp(acctstarttime),              acctterminatecause =  '%{Acct-Terminate-Cause}',              acctstopdelay      =  %{%{Acct-Delay-Time}:-0}           WHERE acctstoptime IS NULL           AND nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <= '%S' ->           UPDATE radacct           SET              acctstoptime       =  '2017-02-03 05:40:14',              acctsessiontime    =  unix_timestamp('2017-02-03 05:40:14') -                                    unix_timestamp(acctstarttime),              acctterminatecause =  'NAS-Reboot',              acctstopdelay      =  0           WHERE acctstoptime IS NULL           AND nasipaddress      =  '192.168.2.3'           AND acctstarttime     <= '2017-02-03 05:40:14'
rlm_sql (sql): Reserving sql socket id: 31
rlm_sql (sql): Released sql socket id: 31
+++[sql] = ok
++} # policy redundant = ok
++[exec] = noop
[attr_filter.accounting_response]       expand: %{User-Name} ->
++[attr_filter.accounting_response] = noop
+} # group accounting = ok
Sending Accounting-Response of id 0 to 192.168.2.3 port 50336
Finished request 0.
Cleaning up request 0 ID 0 with timestamp +129
Going to the next request
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=1, length=163
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x0269000b017363696c656b
        Message-Authenticator = 0x74edf84af030b37a534fbcd907ca3e06
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] EAP packet type response id 105 length 11
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[files] = noop
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
rlm_sql (sql): Reserving sql socket id: 30
[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 = 'scilek'           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 = 'scilek'           ORDER BY id
rlm_sql (sql): Released sql socket id: 30
+++[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-22-FA-F5-B9-0A
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] = notfound
++[expiration] = noop
++[logintime] = noop
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!    Replacing User-Password in config items with Cleartext-Password.     !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Please update your configuration so that the "known good"               !!!
!!! clear text password is in Cleartext-Password, and not in User-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] EAP Identity
[eap] processing type tls
[tls] Flushing SSL sessions (of #0)
[tls] Initiate
[tls] Start returned 1
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 1 to 192.168.2.3 port 49969
        Session-Timeout := 600
        EAP-Message = 0x016a00061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xba3f8732ba559297c826ab9ae9cc2649
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=2, length=226
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x026a00381500160301002d0100002903012ec088aaf7ca3e9706082297b02b5d3dd6eab5884036d26f772e54e92982d0af000002000a0100
        State = 0xba3f8732ba559297c826ab9ae9cc2649
        Message-Authenticator = 0x24b1f6bc8ffa16601f54de045d6943c4
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] 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 004a], ServerHello
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 08d0], 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.2.3 port 49969
        EAP-Message = 0x016b040015c00000092d160301004a02000046030100888678db0d436317a01b2be3945f93f7019a5c4d36a25e41ac24f57c64e8f820cfcf92bce9328eef2bb9f8401fe3de60812b0937bd1d4da02e546ba839e6d3c1000a0016030108d00b0008cc0008c90003de308203da308202c2a003020102020101300d06092a864886f70d01010b0500308193310b3009060355040613024652310f300d06035504080c065261646975733112301006035504070c09536f6d65776865726531153013060355040a0c0c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126302406035504
        EAP-Message = 0x030c1d4578616d706c6520436572746966696361746520417574686f72697479301e170d3137303130393139323531335a170d3138303130393139323531335a307c310b3009060355040613024652310f300d06035504080c0652616469757331153013060355040a0c0c4578616d706c6520496e632e3123302106035504030c1a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100b49d62ff281541ed63615fe14bc91da7af29fd8942f19fd379bfcfd9fdad
        EAP-Message = 0x63ff49e70eb759e42fb675e737955fa4c987e6acfff265adcfc02b0633689261b9c6142e97ae679975aed7c20d986be0363fde4f93af41627ca0c4777db8c7d1854b683ded25e4a27127974480929a700dc2472801c12adb205709ec21c82f336c861e30d2932abfc4e05eab6b9c0018ed98ae7d59f74f96080f1a6d54a35b466b68cd0c62475a47c2e724dfbcbb95802587cf76dda3e0e7a975a5c7a76de60a9f8a564b8ff9aba4e53f59e04d3c808c39076ececdd4f25a3f216e2713d052ee47211d67b4b4e95827a3ce956be6126379d958a979f56b20c20a56ed22b65a77f7a70203010001a34f304d30130603551d25040c300a06082b06010505
        EAP-Message = 0x07030130360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e636f6d2f6578616d706c655f63612e63726c300d06092a864886f70d01010b050003820101005859d5dee5a7030468300d7a1c98b25b2d313515867b7e79e6d62cef1f0a7cb2ffe4f9462f69d91fa24f328a6bfc4a5df08e5dbe56a20a9c7f7a8ded641c26fa0ba7435ea4d64a03b491f9353af1480c12fa48d1690c029dd7cfeb4034a1611264033ba2f32715105c2bed7065a2f3b53fd8f0fa280a7bb4c4e041e4c215bf261426ac28e38a048942a29f129f34a5e2a15609c0064ee33772bbae0fb33cbe5ffdbc5f57a532b0e9b2d3664b4e7a
        EAP-Message = 0x9460214befb4b1e94eb8004a
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xba3f8732bb549297c826ab9ae9cc2649
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=3, length=176
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x026b00061500
        State = 0xba3f8732bb549297c826ab9ae9cc2649
        Message-Authenticator = 0x402f6d69bf7433ebe98510dc36bb3232
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] 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.2.3 port 49969
        EAP-Message = 0x016c040015c00000092d1fe612698018a84d7a7833518263152b81edc6195ff2e5e59c9670843fed4f923f9c54ba171cddaa0b2e854bf4f01a38c2b279e8d7ec8b714817b5bcfc8ff719f463f321c3aa0004e5308204e1308203c9a0030201020209009e689462aa4b3707300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d06035504080c065261646975733112301006035504070c09536f6d65776865726531153013060355040a0c0c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126302406035504030c1d4578616d706c65204365
        EAP-Message = 0x72746966696361746520417574686f72697479301e170d3137303130393139323531335a170d3138303130393139323531335a308193310b3009060355040613024652310f300d06035504080c065261646975733112301006035504070c09536f6d65776865726531153013060355040a0c0c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126302406035504030c1d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100ca5b9546fe4852c583daa7d5b0e84e2764d918
        EAP-Message = 0xe32e22aca6ef32c8dd39530ac4ae70760e346a4c39ac70b1a51531fe624c4d81275113dff5280810db9f62d8423b5226b51934a5b1f9f5e863473df6be72266c39c579cf46d80c03797c803170acb2be176e1140d7f6e2dd2f96ee555123b6a9aabf0edc583b2d92b67db751119cde1c92bd2e4afc2b16b3c8fffe9aa69987da9fa81c440d070db5b620e4dda4d8e1fb8747bc02c93d3776d00e9bde07e068e4b9b898d4b977145ad2c9f61d749b242e20cf720a092ff41694668df8b9a92f3a1141bcf839227509de9a0813d6c9279a4c32062a9853f95253e381d4d3c06d35c840a596a26c24c084811c6e6d0203010001a382013430820130301d06
        EAP-Message = 0x03551d0e0416041408b00f3abaa9725c669e2200b70f0f1a9a5392a73081c80603551d230481c03081bd801408b00f3abaa9725c669e2200b70f0f1a9a5392a7a18199a48196308193310b3009060355040613024652310f300d06035504080c065261646975733112301006035504070c09536f6d65776865726531153013060355040a0c0c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126302406035504030c1d4578616d706c6520436572746966696361746520417574686f726974798209009e689462aa4b3707300c0603551d13040530030101ff30360603551d1f04
        EAP-Message = 0x2f302d302ba029a027862568
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xba3f8732b8539297c826ab9ae9cc2649
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=4, length=176
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x026c00061500
        State = 0xba3f8732b8539297c826ab9ae9cc2649
        Message-Authenticator = 0xc1a7cf4ddfaf1861426e7160c198056f
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] 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.2.3 port 49969
        EAP-Message = 0x016d014b15800000092d7474703a2f2f7777772e6578616d706c652e636f6d2f6578616d706c655f63612e63726c300d06092a864886f70d0101050500038201010073f69421d62527741db69cbe68d3b2bee94581de83862e48f28fa814ef5058eb30fd3d65989cb8da814b64bc09a38b42574f93c75d0bbd4564554fbdf8c6abb8674586ce59d241c649a2fa89b7ac090713b8de839ba9fef66c6f7b744df1dedc103d112aabb893c9db8821641fa9c531e35e9719bb3cce5617c18d9352daa3a9679435f450d8a297cb0758cc2d5d0c2b69b697f62fc61513044aef58c2c12eb150effd0774ec75a0680a2e6c27300196eff4da075876c5a7f80ff6
        EAP-Message = 0x49aa571e5d67fe533a2f7ce73e1e5491147f076c3328d4f671c9e33600b930274f3b48b347647d4ac10471af9feb2a8bc3b6c72df9753307851aec9a485808237b8b52ad3b16030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xba3f8732b9529297c826ab9ae9cc2649
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=5, length=496
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x026d014415001603010106100001020100a30c2fac521aea40ffdfd7bbd11676465cacfdd8fa54cfa41d7972f084d60609c6af83a6c0157825b8375c9830927652a9ef9f93031350f18197a7aa40e1a1115e08b990d3b77fac42a0d31673de425bbbc0ecbed3275e93d312ecb13c5acedd7bc5b468d8ec5372309c2f10374ff54558d03adecc29cc08020bc139417efd6f600b04cea7349220e66548405f1af3bc88006a67ae1b0d894ef411506e5e9ac33183685087b39e7125ac54fd174be7ae551794830c5757fabb41440497012989d72ab6deac77dd47ed25dd197a71fba1e81fd1d71c8f9d821b9bdbf1ca63f87682fda495136226f463984123
        EAP-Message = 0xc6e0e7d029dab1e3e9144b1cc318fe3e8d4fa76e1403010001011603010028ea4ed5d2862daf29b6d50514de77768234c7e3bb59aa50aeb006d739f4de9b5453c11c4156c614e4
        State = 0xba3f8732b9529297c826ab9ae9cc2649
        Message-Authenticator = 0xd4f689d6b0a7835a0a7184eb161bdec0
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] 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
  SSL: adding session cfcf92bce9328eef2bb9f8401fe3de60812b0937bd1d4da02e546ba839e6d3c1 to cache
[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.2.3 port 49969
        EAP-Message = 0x016e003d15800000003314030100010116030100280d5069e675e456ecd3417c5d9301ded1c531ec7ad6c596dbfe6090811fd0734797c3e7204c217e83
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xba3f8732be519297c826ab9ae9cc2649
Finished request 5.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.2.3 port 49969, id=6, length=237
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x026e0043150017030100389c75286e1d6b3101c3d18f76cc38a9f67fe97019d24480cd692303f3cd72bc8612443ee79f4a081384d606080d107fd07dcde3bffbbd6530
        State = 0xba3f8732be519297c826ab9ae9cc2649
        Message-Authenticator = 0x4985982e3592aae5b4886bc25e1c1520
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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] 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 = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        NAS-IP-Address = 192.168.2.3
server  {
# Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
++[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: 29
[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 = 'scilek'           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 = 'scilek'           ORDER BY id
rlm_sql (sql): Released sql socket id: 29
+++[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-22-FA-F5-B9-0A
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
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!    Replacing User-Password in config items with Cleartext-Password.     !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Please update your configuration so that the "known good"               !!!
!!! clear text password is in Cleartext-Password, and not in User-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
# 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: SELECT COUNT(*)                              FROM radacct                              WHERE username = '%{SQL-User-Name}'                              AND acctstoptime IS NULL -> SELECT COUNT(*)                              FROM radacct                              WHERE username = 'scilek'                              AND acctstoptime IS NULL
rlm_sql (sql): Reserving sql socket id: 28
rlm_sql (sql): Released sql socket id: 28
+++[sql] = ok
++} # policy redundant = ok
+} # group session = ok
        expand:  ->
Login OK: [scilek] (from client HOME_AP port 0 cli 00-22-FA-F5-B9-0A via TLS tunnel)
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
+group post-auth {
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
        Session-Timeout := 600
        Exec-Program-Wait = "/usr/local/bin/bash /usr/local/etc/raddb/scripts/sql_datacounter_auth.sh scilek"
[ttls] Got tunneled Access-Accept
[ttls] Saving response in the cache
[ttls] WARNING: No information to cache: session caching will be disabled for this session.
  SSL: Removing session cfcf92bce9328eef2bb9f8401fe3de60812b0937bd1d4da02e546ba839e6d3c1 from the cache
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
        expand:  ->
Login OK: [scilek] (from client HOME_AP port 0 cli 00-22-FA-F5-B9-0A)
# Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
+group post-auth {
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.2.3 port 49969
        Session-Timeout := 600
        MS-MPPE-Recv-Key = 0x1d947c3faad1e8527f1c926add5db9ca75c0c18a05ccbe36f17bed482d4fbc74
        MS-MPPE-Send-Key = 0xcd56c6e98169b127fbe7fa63ad3e58bb381eca5a58e8b8ff0773fc4f31f177b2
        EAP-Message = 0x036e0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "scilek"
Finished request 6.
Going to the next request
Waking up in 4.4 seconds.
rad_recv: Accounting-Request packet from host 192.168.2.3 port 50336, id=7, length=157
        Acct-Session-Id = "5893ED8E-00000000"
        Acct-Status-Type = Start
        Acct-Authentic = RADIUS
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
# 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} ->  1486089714 - 0 - 0
        expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1486089714
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "802aa8ac1ef9",NAS-IP-Address = 192.168.2.3,Acct-Session-Id = "5893ED8E-00000000",User-Name = "scilek"'
[acct_unique] Acct-Unique-Session-ID = "26952a088fe1734e".
++[acct_unique] = ok
[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 {
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.2.3
[detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.2.3/detail-20170203
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.2.3/detail-20170203
[detail]        expand: %t -> Fri Feb  3 05:41:54 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
[radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
[radutmp]       expand: %{User-Name} -> scilek
++[radutmp] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: %{Acct-Delay-Time} ->
[sql]   ... expanding second conditional
[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: 27
rlm_sql (sql): Released sql socket id: 27
+++[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.2.3 port 50336
Finished request 7.
Cleaning up request 7 ID 7 with timestamp +229
Going to the next request
Waking up in 4.1 seconds.
Cleaning up request 1 ID 1 with timestamp +228
Cleaning up request 2 ID 2 with timestamp +228
Cleaning up request 3 ID 3 with timestamp +228
Cleaning up request 4 ID 4 with timestamp +228
Waking up in 0.2 seconds.
Cleaning up request 5 ID 5 with timestamp +228
Waking up in 0.2 seconds.
Cleaning up request 6 ID 6 with timestamp +228
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.2.3 port 50336, id=8, length=199
        Acct-Session-Id = "5893ED8E-00000000"
        Acct-Status-Type = Stop
        Acct-Authentic = RADIUS
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        Acct-Session-Time = 600
        Acct-Input-Packets = 25902
        Acct-Output-Packets = 25367
        Acct-Input-Octets = 38351862
        Acct-Output-Octets = 37234905
        Event-Timestamp = "Feb  3 2017 05:51:54 MSK"
        Acct-Terminate-Cause = Session-Timeout
# Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
+group preacct {
++[preprocess] = ok
++update request {
        expand: %{Acct-Session-Time} -> 600
        expand: %{Acct-Delay-Time} ->
        ... expanding second conditional
        expand:  %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} ->  1486090314 - 600 - 0
        expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1486089714
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "802aa8ac1ef9",NAS-IP-Address = 192.168.2.3,Acct-Session-Id = "5893ED8E-00000000",User-Name = "scilek"'
[acct_unique] Acct-Unique-Session-ID = "26952a088fe1734e".
++[acct_unique] = ok
[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 {
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.2.3
[detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.2.3/detail-20170203
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.2.3/detail-20170203
[detail]        expand: %t -> Fri Feb  3 05:51:54 2017
++[detail] = ok
rlm_counter: Packet Unique ID = '26952a088fe1734e'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '6e394fe62dee48f1'
rlm_counter: User=scilek, Counter=237.
rlm_counter: User=scilek, New Counter=837.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[daily] = ok
rlm_counter: Packet Unique ID = '26952a088fe1734e'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '6e394fe62dee48f1'
rlm_counter: User=scilek, Counter=14389.
rlm_counter: User=scilek, New Counter=14989.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[weekly] = ok
rlm_counter: Packet Unique ID = '26952a088fe1734e'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '6e394fe62dee48f1'
rlm_counter: User=scilek, Counter=14389.
rlm_counter: User=scilek, New Counter=14989.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[monthly] = ok
rlm_counter: Packet Unique ID = '26952a088fe1734e'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '6e394fe62dee48f1'
rlm_counter: User=scilek, Counter=80421.
rlm_counter: User=scilek, New Counter=81021.
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]      expand: %{request:User-Name} -> scilek
[datacounterdaily]      expand: %{request:Acct-Input-Octets} -> 38351862
[datacounterdaily]      expand: %{request:Acct-Output-Octets} -> 37234905
[datacounterdaily]      expand: %{request:Acct-Status-Type} -> Stop
[datacounterdaily]      expand: %{request:Acct-Session-Id} -> 5893ED8E-00000000
Exec output:
[datacounterdaily] Exec: program returned: 0
+++[datacounterdaily] = ok
[datacounterweekly]     expand: %{request:User-Name} -> scilek
[datacounterweekly]     expand: %{request:Acct-Input-Octets} -> 38351862
[datacounterweekly]     expand: %{request:Acct-Output-Octets} -> 37234905
[datacounterweekly]     expand: %{request:Acct-Status-Type} -> Stop
[datacounterweekly]     expand: %{request:Acct-Session-Id} -> 5893ED8E-00000000
Exec output:
[datacounterweekly] Exec: program returned: 0
+++[datacounterweekly] = ok
[datacountermonthly]    expand: %{request:User-Name} -> scilek
[datacountermonthly]    expand: %{request:Acct-Input-Octets} -> 38351862
[datacountermonthly]    expand: %{request:Acct-Output-Octets} -> 37234905
[datacountermonthly]    expand: %{request:Acct-Status-Type} -> Stop
[datacountermonthly]    expand: %{request:Acct-Session-Id} -> 5893ED8E-00000000
Exec output:
[datacountermonthly] Exec: program returned: 0
+++[datacountermonthly] = ok
[datacounterforever]    expand: %{request:User-Name} -> scilek
[datacounterforever]    expand: %{request:Acct-Input-Octets} -> 38351862
[datacounterforever]    expand: %{request:Acct-Output-Octets} -> 37234905
[datacounterforever]    expand: %{request:Acct-Status-Type} -> Stop
[datacounterforever]    expand: %{request:Acct-Session-Id} -> 5893ED8E-00000000
Exec output:
[datacounterforever] Exec: program returned: 0
+++[datacounterforever] = ok
++} # if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) = ok
++[unix] = ok
[radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
[radutmp]       expand: %{User-Name} -> scilek
++[radutmp] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: %{Acct-Session-Time} -> 600
[sql]   expand: %{Acct-Input-Gigawords} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Acct-Input-Octets} -> 38351862
[sql]   expand: %{Acct-Output-Gigawords} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Acct-Output-Octets} -> 37234905
[sql]   expand: %{Acct-Delay-Time} ->
[sql]   ... expanding second conditional
[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       = '2017-02-03 05:51:54',              acctsessiontime    = '600',              acctinputoctets    = '0' << 32 |                                   '38351862',              acctoutputoctets   = '0
rlm_sql (sql): Reserving sql socket id: 26
rlm_sql (sql): Released sql socket id: 26
+++[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.2.3 port 50336
Finished request 8.
Cleaning up request 8 ID 8 with timestamp +829
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.2.3 port 50336, id=9, length=157
        Acct-Session-Id = "5893ED8E-00000001"
        Acct-Status-Type = Start
        Acct-Authentic = RADIUS
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
# 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} ->  1486090314 - 0 - 0
        expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1486090314
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "802aa8ac1ef9",NAS-IP-Address = 192.168.2.3,Acct-Session-Id = "5893ED8E-00000001",User-Name = "scilek"'
[acct_unique] Acct-Unique-Session-ID = "f023d324ba7f522f".
++[acct_unique] = ok
[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 {
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.2.3
[detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.2.3/detail-20170203
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.2.3/detail-20170203
[detail]        expand: %t -> Fri Feb  3 05:51:54 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
[radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
[radutmp]       expand: %{User-Name} -> scilek
++[radutmp] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: %{Acct-Delay-Time} ->
[sql]   ... expanding second conditional
[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: 25
rlm_sql (sql): Released sql socket id: 25
+++[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 9 to 192.168.2.3 port 50336
Finished request 9.
Cleaning up request 9 ID 9 with timestamp +829
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.2.3 port 50336, id=10, length=199
        Acct-Session-Id = "5893ED8E-00000001"
        Acct-Status-Type = Stop
        Acct-Authentic = RADIUS
        User-Name = "scilek"
        NAS-Identifier = "802aa8ac1ef9"
        NAS-Port = 0
        Called-Station-Id = "80-2A-A8-AD-1E-F9:SCILEK.NET"
        Calling-Station-Id = "00-22-FA-F5-B9-0A"
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        Acct-Session-Time = 699
        Acct-Input-Packets = 31647
        Acct-Output-Packets = 31001
        Acct-Input-Octets = 47285431
        Acct-Output-Octets = 45668506
        Event-Timestamp = "Feb  3 2017 06:03:33 MSK"
        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} -> 699
        expand: %{Acct-Delay-Time} ->
        ... expanding second conditional
        expand:  %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} ->  1486091013 - 699 - 0
        expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1486090314
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "802aa8ac1ef9",NAS-IP-Address = 192.168.2.3,Acct-Session-Id = "5893ED8E-00000001",User-Name = "scilek"'
[acct_unique] Acct-Unique-Session-ID = "f023d324ba7f522f".
++[acct_unique] = ok
[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 {
[detail]        expand: %{Packet-Src-IP-Address} -> 192.168.2.3
[detail]        expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.2.3/detail-20170203
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.2.3/detail-20170203
[detail]        expand: %t -> Fri Feb  3 06:03:33 2017
++[detail] = ok
rlm_counter: Packet Unique ID = 'f023d324ba7f522f'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '26952a088fe1734e'
rlm_counter: User=scilek, Counter=837.
rlm_counter: User=scilek, New Counter=1536.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[daily] = ok
rlm_counter: Packet Unique ID = 'f023d324ba7f522f'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '26952a088fe1734e'
rlm_counter: User=scilek, Counter=14989.
rlm_counter: User=scilek, New Counter=15688.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[weekly] = ok
rlm_counter: Packet Unique ID = 'f023d324ba7f522f'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '26952a088fe1734e'
rlm_counter: User=scilek, Counter=14989.
rlm_counter: User=scilek, New Counter=15688.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[monthly] = ok
rlm_counter: Packet Unique ID = 'f023d324ba7f522f'
rlm_counter: Searching the database for key 'scilek'
rlm_counter: Key found.
rlm_counter: Counter Unique ID = '26952a088fe1734e'
rlm_counter: User=scilek, Counter=81021.
rlm_counter: User=scilek, New Counter=81720.
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]      expand: %{request:User-Name} -> scilek
[datacounterdaily]      expand: %{request:Acct-Input-Octets} -> 47285431
[datacounterdaily]      expand: %{request:Acct-Output-Octets} -> 45668506
[datacounterdaily]      expand: %{request:Acct-Status-Type} -> Stop
[datacounterdaily]      expand: %{request:Acct-Session-Id} -> 5893ED8E-00000001
Exec output:
[datacounterdaily] Exec: program returned: 0
+++[datacounterdaily] = ok
[datacounterweekly]     expand: %{request:User-Name} -> scilek
[datacounterweekly]     expand: %{request:Acct-Input-Octets} -> 47285431
[datacounterweekly]     expand: %{request:Acct-Output-Octets} -> 45668506
[datacounterweekly]     expand: %{request:Acct-Status-Type} -> Stop
[datacounterweekly]     expand: %{request:Acct-Session-Id} -> 5893ED8E-00000001
Exec output:
[datacounterweekly] Exec: program returned: 0
+++[datacounterweekly] = ok
[datacountermonthly]    expand: %{request:User-Name} -> scilek
[datacountermonthly]    expand: %{request:Acct-Input-Octets} -> 47285431
[datacountermonthly]    expand: %{request:Acct-Output-Octets} -> 45668506
[datacountermonthly]    expand: %{request:Acct-Status-Type} -> Stop
[datacountermonthly]    expand: %{request:Acct-Session-Id} -> 5893ED8E-00000001
Exec output:
[datacountermonthly] Exec: program returned: 0
+++[datacountermonthly] = ok
[datacounterforever]    expand: %{request:User-Name} -> scilek
[datacounterforever]    expand: %{request:Acct-Input-Octets} -> 47285431
[datacounterforever]    expand: %{request:Acct-Output-Octets} -> 45668506
[datacounterforever]    expand: %{request:Acct-Status-Type} -> Stop
[datacounterforever]    expand: %{request:Acct-Session-Id} -> 5893ED8E-00000001
Exec output:
[datacounterforever] Exec: program returned: 0
+++[datacounterforever] = ok
++} # if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) = ok
++[unix] = ok
[radutmp]       expand: /var/log/radutmp -> /var/log/radutmp
[radutmp]       expand: %{User-Name} -> scilek
++[radutmp] = ok
++policy redundant {
[sql]   expand: %{User-Name} -> scilek
[sql] sql_set_user escaped user --> 'scilek'
[sql]   expand: %{Acct-Session-Time} -> 699
[sql]   expand: %{Acct-Input-Gigawords} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Acct-Input-Octets} -> 47285431
[sql]   expand: %{Acct-Output-Gigawords} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Acct-Output-Octets} -> 45668506
[sql]   expand: %{Acct-Delay-Time} ->
[sql]   ... expanding second conditional
[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       = '2017-02-03 06:03:33',              acctsessiontime    = '699',              acctinputoctets    = '0' << 32 |                                   '47285431',              acctoutputoctets   = '0
rlm_sql (sql): Reserving sql socket id: 24
rlm_sql (sql): Released sql socket id: 24
+++[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 10 to 192.168.2.3 port 50336
Finished request 10.
Cleaning up request 10 ID 10 with timestamp +1528
Going to the next request
Ready to process requests.