Some Android smartphones send only accounting request

Riccardo locatelli riccardo.locatelli at netweek.it
Tue Aug 18 10:45:02 CEST 2015


Hi

I Use CentOs 6.7 with freeradius 2.2.6 (tested also with 2.2.8 -> same
problem).

The problem is that some Android devices (including the galaxy s5) to the
first access send access-request and accounting-request (all ok), in
subsequent connections instead send only accounting-request.

the clients connect anyway, but bypass the controls on attributes. (I
use Simultaneous-Use := 1 that is in the group "base")

summarize:
+connect android
+disconnect android
+connect pc
+ reconnect android (should check Simultaneous-Use but not work)


This problem occurs only with some client Android. with other devices work
vey well (pc send always access and accouting request).

below the first connection:
-------------------------------------------------------------------------------------------------------------------------------------
radiusd: FreeRADIUS Version 2.2.6, for host x86_64-unknown-linux-gnu, built
on F

          eb 18 2015 at 16:53:34
Copyright (C) 1999-2013 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/proxy.conf
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/ntlm_auth
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/dynamic_clients
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/smsotp
including configuration file /usr/local/etc/raddb/modules/radrelay
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/always
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/rediswho
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/soh
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/cache
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/redis
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/perl
including configuration file /usr/local/etc/raddb/modules/replicate
including configuration file
/usr/local/etc/raddb/modules/sqlcounter_expire_on_l

                                                        ogin
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/cui
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/otp
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/detail.example.com
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/preprocess
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
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/krb5
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/files
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/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/inner-tunnel
including configuration file
/usr/local/etc/raddb/sites-enabled/control-socket
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 = "/usr/local/var"
        sbindir = "/usr/local/sbin"
        logdir = "/usr/local/var/log/radius"
        run_dir = "/usr/local/var/run/radiusd"
        libdir = "/usr/local/lib"
        radacctdir = "/usr/local/var/log/radius/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 1024
        pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
        checkrad = "/usr/local/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = no
        auth_badpass = yes
        auth_goodpass = yes
 }
 security {
        max_attributes = 200
        reject_delay = 1
        status_server = no
        allow_vulnerable_openssl = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 home_server localhost {
        ipaddr = 127.0.0.1
        port = 1812
        type = "auth"
        secret = "testing123"
        response_window = 20
        max_outstanding = 65536
        require_message_authenticator = yes
        zombie_period = 40
        status_check = "status-server"
        ping_interval = 30
        check_interval = 30
        num_answers_to_alive = 3
        num_pings_to_alive = 3
        revive_interval = 120
        status_check_timeout = 4
  coa {
        irt = 2
        mrt = 16
        mrc = 5
        mrd = 30
  }
 }
 home_server_pool my_auth_failover {
        type = fail-over
        home_server = localhost
 }
 realm example.com {
        auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
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
  }
 }
radiusd: #### Loading Virtual Servers ####
server { # from file /usr/locp"?▒
 modules {
  Module: Creating Post-Auth-Type = REJECT
 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/ms

                                    chap
  mschap {
        use_mppe = yes
        require_encryption = yes
        require_strong = yes
        with_ntdomain_hack = no
        allow_retry = yes
  }
 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 = 2
        ignore_unknown_eap_types = yes
        cisco_accounting_username_bug = no
        max_sessions = 1024
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
        challenge = "Password: "
        auth_type = "PAP"
   }
 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
        pem_file_type = yes
        private_key_file = "/usr/local/etc/raddb/certs/server.key"
        certificate_file = "/usr/local/etc/raddb/certs/server.pem"
        private_key_password = *******
        dh_file = "/usr/local/etc/raddb/certs/dh"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
        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 = "md5"
        copy_request_to_tunnel = yes
        use_tunneled_reply = yes
        virtual_server = "inner-tunnel"
        include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
        default_eap_type = "mschapv2"
        copy_request_to_tunnel = yes
        use_tunneled_reply = yes
        proxy_tunneled_request_as_eap = yes
        virtual_server = "inner-tunnel"
        soh = no
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
        with_ntdomain_hack = no
        send_error = yes
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating module "preprocess" from file
/usr/local/etc/raddb/module

                                s/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_sql
 Module: Instantiating module "sql" from file /usr/local/etc/raddb/sql.conf
  sql {
        driver = "rlm_sql_mysql"
        server = "localhost"
        port = "3306"
        login = "radius"
        password = "radpass"
        radius_db = "radius"
        read_groups = yes
        sqltrace = yes
        sqltracefile = "/usr/local/var/log/radius/sqltrace.sql"
        readclients = yes
        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 na

            s"
        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-Grou

                  p}'           ORDER BY id"
        authorize_group_reply_query = "SELECT id, groupname, attribute,


           value, op           FROM radgroupreply           WHERE groupname
= '%{Sql-Grou

                  p}'           ORDER BY id"
        accounting_onoff_query = "          UPDATE radacct           SET


                acctstoptime       =  '%S',              acctsessiontime
 =  unix_timest

                    amp('%S') -
 unix_timestamp(acctstarttime),

                                                  acctterminatecause =
 '%{Acct-Terminate-Cause}',              acctsto

                                                      pdelay      =
 %{%{Acct-Delay-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

                           = '%{%{Acct-Session-Time}:-0}',
 acctinputoctets     = '%{%{Acct-

                                      Input-Gigawords}:-0}'  << 32 |
                             '%{%{Acct-Inpu

                                                t-Octets}:-0}',
 acctoutputoctets    = '%{%{Acct-Output-Gigawords}:-

                                                          0}' << 32 |
                             '%{%{Acct-Output-Octets}:-0}'


 WHERE acctsessionid = '%{Acct-Session-Id}'           AND username


    = '%{SQL-User-Name}'           AND nasipaddress    =
'%{NAS-IP-Address}'"
        accounting_update_query_alt = "           INSERT INTO radacct


           (acctsessionid,    acctuniqueid,      username,
 realm,

                        nasipaddress,      nasportid,
 nasporttype,      acctstarttime,

                                           acctsessiontime,
 acctauthentic,    connectinfo_start, acctinputoct

                                                        ets,
 acctoutputoctets, calledstationid,   callingstationid,


servicetype,      framedprotocol,    framedipaddress,              acctsta


    rtdelay,   xascendsessionsvrkey)           VALUES
('%{Acct-Session-I

                        d}', '%{Acct-Unique-Session-Id}',
 '%{SQL-User-Name}',

                                        '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}',              '%{NAS-Port-Type}',


DATE_SUB('%S',                       INTERVAL (%{%{Acct-Session-Ti


me}:-0} +                                 %{%{Acct-Delay-Time}:-0})
SECOND),

                                     '%{%{Acct-Session-Time}:-0}',
     '%{Acct-Authentic}

                            ', '',
 '%{%{Acct-Input-Gigawords}:-0}' << 32 |              '%{%{Ac


ct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}' << 32
|

                    '%{%{Acct-Output-Octets}:-0}',
 '%{Called-Station-Id}', '%

                                {Calling-Station-Id}',
 '%{Service-Type}', '%{Framed-Protocol}',


'%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}


')"
        accounting_start_query = "           INSERT INTO radacct
  (ac

          ctsessionid,    acctuniqueid,     username,              realm,
         nasip

                    address,     nasportid,              nasporttype,
 acctstarttime,    acctsto

                                ptime,              acctsessiontime,
 acctauthentic,    connectinfo_start,

                                                        connectinfo_stop,
acctinputoctets,  acctoutputoctets,              calle

                                                            dstationid,
 callingstationid, acctterminatecause,              servicetype,


framedprotocol,   framedipaddress,              acctstartdelay,
acctstopdela

                  y,    xascendsessionsvrkey)           VALUES
('%{Acct-Session-Id}',

                             '%{Acct-Unique-Session-Id}',
 '%{SQL-User-Name}',              '%{Re

                                            alm}', '%{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 accts

                                            essionid  =
'%{Acct-Session-Id}'           AND username         = '%{SQL-User-Na


me}'           AND nasipaddress     = '%{NAS-IP-Address}'"
        accounting_stop_query = "           UPDATE radacct SET
 acct

          stoptime       = '%S',              acctsessiontime    =
'%{%{Acct-Session-Time}

                            :-0}',              acctinputoctets    =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |


   '%{%{Acct-Input-Octets}:-0}',              ac

                                                      ctoutputoctets   =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |


     '%{%{Acct-Output-Octets}:-0}',              acctterminatecause = '


%{Acct-Terminate-Cause}',              acctstopdelay      =
'%{%{Acct-Delay-Time

                          }:-0}',              connectinfo_stop   =
'%{Connect-Info}'           WHERE acct

                                            sessionid   =
'%{Acct-Session-Id}'           AND username          = '%{SQL-User


-Name}'           AND nasipaddress      = '%{NAS-IP-Address}'"
        accounting_stop_query_alt = "           INSERT INTO radacct


         (acctsessionid, acctuniqueid, username,              realm,
nasipaddress, naspor

                          tid,              nasporttype, acctstarttime,
acctstoptime,              acctses

                                        siontime, acctauthentic,
connectinfo_start,              connectinfo_stop, accti

                                                            nputoctets,
acctoutputoctets,              calledstationid, callingstationid, ac


ctterminatecause,              servicetype, framedprotocol,
framedipaddress,

                                    acctstartdelay, acctstopdelay)
  VALUES             ('%{Acct-S

                                    ession-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}:-0}) SECOND),              '%

                                                        S',
'%{%{Acct-Session-Time}:-0}', '%{Acct-Authentic}', '',
 '%{Conne

              ct-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32
|              '%{

                        %{Acct-Input-Octets}:-0}',
 '%{%{Acct-Output-Gigawords}:-0}' << 32 |


'%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}'

                                                                        ,
'%{Calling-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 r

            adacct                              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
(use

          rname, pass, reply, authdate)                           VALUES (


                               '%{User-Name}',
'%{%{User-Password}:-%{Chap

                                -Password}}',
'%{reply:Packet-Type}', '%S')"
        safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ

                                                            0123456789.-_:
/"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius at localhost:3306/radius
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
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname,
shortname, t

                  ype, secret, server FROM nas
rlm_sql (sql): Reserving sql socket id: 31
rlm_sql_mysql: query:  SELECT id, nasname, shortname, type, secret, server
FROM

           nas
rlm_sql (sql): Read entry
nasname=192.168.16.249,shortname=cisco121,secret=DMedi

                                                            aRadius
rlm_sql (sql): Adding client 192.168.16.249 (cisco121, server=<none>) to
clients

             list
rlm_sql (sql): Read entry nasname=192.168.100.110,shortname=SysEdit
Trunk,secret

                  =DMediaRadius
rlm_sql (sql): Adding client 192.168.100.110 (SysEdit Trunk, server=<none>)
to c

          lients list
rlm_sql (sql): Released sql socket id: 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/modul

                                es/acct_unique
  acct_unique {
        key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier,
NAS-P

          ort, Event-Timestamp"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_always
 Module: Instantiating module "ok" from file
/usr/local/etc/raddb/modules/always
  always ok {
        rcode = "ok"
        simulcount = 0
        mpp = no
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating module "attr_filter.accounting_response" from file
/usr/l

            ocal/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 post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Instantiating module "attr_filter.access_reject" from file
/usr/local/e

                  tc/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
server inner-tunnel { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunne

                                                    l
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "auth"
        ipaddr = *
        port = 0
}
listen {
        type = "acct"
        ipaddr = *
        port = 0
}
listen {
        type = "control"
 listen {
        socket = "/usr/local/var/run/radiusd/radiusd.sock"
 }
}
listen {
        type = "auth"
        ipaddr = 127.0.0.1
        port = 18120
}
 ... adding new socket proxy address * port 59911
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Listening on authentication address 127.0.0.1 port 18120 as server
inner-tunnel
Listening on proxy address * port 1814
Ready to process requests.







rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=239, length=148
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024300090174657374
        Message-Authenticator = 0xa6257642b7a4b8926ca010d782c675af
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 67 length 9
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 67 length 9
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'test'           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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'test'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username = 'test'
      ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
  WHERE username = 'test'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'base'
ORDER BY id
[sql] User found in group base
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'base'
ORDER BY id
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'Agenti'
ORDER BY id
[sql] User found in group Agenti
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'Agenti'
ORDER BY id
rlm_sql (sql): Released sql socket id: 30
++[sql] = ok
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# 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 239 to 192.168.100.110 port 54618
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message = 0x014400061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772355196231559fe392aa31ada6
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=240, length=163
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024400060319
        State = 0x555d772355196231559fe392aa31ada6
        Message-Authenticator = 0x1332beb16cd5dd5a5214aa702b80bab1
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 68 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 68 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'test'           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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'test'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username = 'test'
      ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
  WHERE username = 'test'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'base'
ORDER BY id
[sql] User found in group base
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'base'
ORDER BY id
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'Agenti'
ORDER BY id
[sql] User found in group Agenti
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'Agenti'
ORDER BY id
rlm_sql (sql): Released sql socket id: 29
++[sql] = ok
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/peap
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 240 to 192.168.100.110 port 54618
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message = 0x014500061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772354186e31559fe392aa31ada6
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=241, length=365
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x024500d01980000000c616030100c1010000bd030155d2ef9841b04055ba6f0b5377a1a648b780c35e86defa1d9f586efc24981b7b000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011
        State = 0x555d772354186e31559fe392aa31ada6
        Message-Authenticator = 0x15d2bf9bb638295a0a6b776882bf5d6f
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 69 length 208
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 69 length 208
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 198
[peap] Length Included
[peap] eaptls_verify returned 11
[peap]     (other): before/accept initialization
[peap]     TLS_accept: before/accept initialization
[peap] <<< TLS 1.0 Handshake [length 00c1], ClientHello
[peap]     TLS_accept: SSLv3 read client hello A
[peap] >>> TLS 1.0 Handshake [length 0039], ServerHello
[peap]     TLS_accept: SSLv3 write server hello A
[peap] >>> TLS 1.0 Handshake [length 0c3a], Certificate
[peap]     TLS_accept: SSLv3 write certificate A
[peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
[peap]     TLS_accept: SSLv3 write key exchange A
[peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
[peap]     TLS_accept: SSLv3 write server done A
[peap]     TLS_accept: SSLv3 flush data
[peap]     TLS_accept: Need to read more data: SSLv3 read client
certificate A
[peap]     TLS_accept: Need to read more data: SSLv3 read client
certificate A
In SSL Handshake Phase
In SSL Accept mode
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 241 to 192.168.100.110 port 54618
        EAP-Message =
0x0146040019c000000dd6160301003902000035030155d2ef964fb69684b8a279724236a822c827cac339da17c4adb14eddfe8a801e00c01400000dff01000100000b0004030001021603010c3a0b000c36000c330004a9308204a53082038da0030201020203062bd5300d06092a864886f70d01010b05003047310b300906035504061302555331163014060355040a130d47656f547275737420496e632e3120301e06035504031317526170696453534c20534841323536204341202d204733301e170d3135303830363134343033385a170d3136313030373131313535305a30819531133011060355040b130a475438303833393132383131302f
        EAP-Message =
0x060355040b1328536565207777772e726170696473736c2e636f6d2f7265736f75726365732f637073202863293135312f302d060355040b1326446f6d61696e20436f6e74726f6c2056616c696461746564202d20526170696453534c285229311a3018060355040313117261646975732e6e65747765656b2e697430820122300d06092a864886f70d01010105000382010f003082010a0282010100b834f33060f1a4f40622eede95741d41c6a7c42c98c7478b49ae4d5ffebd971a435a2f09320d57738b065aa25910ea3265c3fa389b8c82712d448bf09f0f5194a3f8c5e57cbe2907871ed28db72b052a9f21d7d5b0d41445447706cf1cdaab9c
        EAP-Message =
0x23c3a39580e637b120d5aeca90f4b28e0e46403dc6d84989cd8a72c5ede5ba3d60f2f299811c814b13f5a727018e7d0504c3c769c9210ce46d9d354c6cafaaf2e0f40bc7169337a85b91d6f4a759130c1b47a53c85bec796d8e0e5481339c9dd9161cde83d562b5b4db0964f38953de3e9b97c94a49320785393c4154eff312f2780309637026d81705424c276c7f39ab7c9c14052818e2805cb5a0fd6523aab0203010001a382014930820145301f0603551d23041830168014c39cf3fcd3460834bbce467fa07c5bf3e208cb59305706082b06010505070101044b3049301f06082b060105050730018613687474703a2f2f67762e73796d63642e63
        EAP-Message =
0x6f6d302606082b06010505073002861a687474703a2f2f67762e73796d63622e636f6d2f67762e637274300e0603551d0f0101ff0404030205a0301d0603551d250416301406082b0601050507030106082b06010505070302301c0603551d110415301382117261646975732e6e65747765656b2e6974302b0603551d1f042430223020a01ea01c861a687474703a2f2f67762e73796d63622e636f6d2f67762e63726c300c0603551d130101ff0402300030410603551d20043a30383036060667810c010201302c302a06082b06010505070201161e68747470733a2f2f7777772e726170696473736c2e636f6d2f6c6567616c300d06092a864886
        EAP-Message = 0xf70d01010b05000382010100
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d7723571b6e31559fe392aa31ada6
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=242, length=163
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024600061900
        State = 0x555d7723571b6e31559fe392aa31ada6
        Message-Authenticator = 0x6ca1bd753b6cec2e922399e6eb4a2a93
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 70 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 70 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 242 to 192.168.100.110 port 54618
        EAP-Message =
0x014703fc1940995a7b7979078073dc176af08f4f83f2991a1e02ba26fdff33c13f0653ad237817e512b59fda3a264090786754e276d5f48dd6191394e05cae4262cf9d818bb580ccca846966292f87c337554a650faedbac6eb33bc1ebe5893b702ced379ef009076f5bf0c202e8beecf9440d6bcde6260ea64ff9366a75ec9ffdceaa9dce74f2fbd915619692045d38f3879c893358cc01bb361b2b7d9ec9a6e9b4d007c58bbf3d181135f81d69456034f3220edb18e1d92860251c1bd26847162b4d3939596e41defc0f01db5bea134b61bb4e1dc6274934ac52d5b3826741074e7143625bcf2d188bff48c4fb2260bb311ead98efaae9da3edb733e
        EAP-Message =
0xb3b724afc4786a0eba000429308204253082030da0030201020203023a77300d06092a864886f70d01010b05003042310b300906035504061302555331163014060355040a130d47656f547275737420496e632e311b30190603550403131247656f547275737420476c6f62616c204341301e170d3134303832393231333933325a170d3232303532303231333933325a3047310b300906035504061302555331163014060355040a130d47656f547275737420496e632e3120301e06035504031317526170696453534c20534841323536204341202d20473330820122300d06092a864886f70d01010105000382010f003082010a0282010100af54
        EAP-Message =
0x9bd9585d1e2c56c6d5e87ff47d1603ffd08b5ae48ea7dd542ed404c05d989c8d900fbc10655fda9ad6447cc09fb5e94a8c0b064304bbf496e226f6610191663122c334345f3f3f912f445fdcc714b6039f864b0ea3ffa0800283c3d31f6952d69d640fc983e71bc470ac94e7c3a46a2cbdb89e69d8be0a8f16635a6871807b30de1504bfccd3bf3e4805557ab3d7100c03fc9bfd08a78c8cdba78ef11e63dcb3012f7faf57c33c48a7836821a72fe7a73ff0b50cfcf584d153bc0e724f600c42b898ad198857d704ec87bf7e874ea321f953fd3698488dd6f8bb48f229c864d1cc5448538bafb7651ebf293329d9296048f8ff91bc5758e5352ebb69b6
        EAP-Message =
0x590203010001a382011d30820119301f0603551d23041830168014c07a98688d89fbab05640c117daa7d65b8cacc4e301d0603551d0e04160414c39cf3fcd3460834bbce467fa07c5bf3e208cb5930120603551d130101ff040830060101ff020100300e0603551d0f0101ff04040302010630350603551d1f042e302c302aa028a0268624687474703a2f2f672e73796d63622e636f6d2f63726c732f6774676c6f62616c2e63726c302e06082b0601050507010104223020301e06082b060105050730018612687474703a2f2f672e73796d63642e636f6d304c0603551d20044530433041060a6086480186f8450107363033303106082b06010505
        EAP-Message = 0x0702011625687474
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d7723561a6e31559fe392aa31ada6
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=243, length=163
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024700061900
        State = 0x555d7723561a6e31559fe392aa31ada6
        Message-Authenticator = 0xe9433b401b680719d86166ea2eb79d96
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 71 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 71 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 243 to 192.168.100.110 port 54618
        EAP-Message =
0x014803fc1940703a2f2f7777772e67656f74727573742e636f6d2f7265736f75726365732f637073300d06092a864886f70d01010b05000382010100a3581ec64332acac2f9378b7eaae5440472d7e788d50f6f866acd64f73d644efaf0bcc5bc1f44f9a8f497e60afc227c716f1fb938190a97cef6f7e6e45941684bdec49f1c40ef4af045983870f2c3b97c35a129b7b04357ba39533087b93712242b3a9d96f4f8192fc07b679bc844a9d7709f1c589f2f0b49c54aa127b0dba4fef9319ecef7d4e61a38e769c59cf8c94b18497f71ab907b8b2c64f1379dbbf4f511b7f690d512ac1d615ff3751346551f41ebe386aec0eabbf3d7b39057bf4f3fb
        EAP-Message =
0x1aa1d0c87e4e648dcd8c615590fe3aca5d250ff81da34a74564f1a5540707525a6332eba4ba55d539a0d30e18d5f612cafccefb099a180ff0bf2624c702698000358308203543082023ca0030201020203023456300d06092a864886f70d01010505003042310b300906035504061302555331163014060355040a130d47656f547275737420496e632e311b30190603550403131247656f547275737420476c6f62616c204341301e170d3032303532313034303030305a170d3232303532313034303030305a3042310b300906035504061302555331163014060355040a130d47656f547275737420496e632e311b30190603550403131247656f54
        EAP-Message =
0x7275737420476c6f62616c20434130820122300d06092a864886f70d01010105000382010f003082010a0282010100dacc186330fdf417231a567e5bdf3c6c38e471b77891d4bca1d84cf8a843b603e94d21070888da582f663929bd05788b9d38e805b76a7e71a4e6c460a6b0ef80e489280f9e25d6ed83f3ada691c798c9421835149dad9846922e4fcaf18743c11695572d50ef892d807a57adf2ee5f6bd2008db914f8141535d9c046a37b72c891bfc9552bcdd0973e9c2664ccdfce831971ca4ee6d4d57ba919cd55dec8ecd25e3853e55c4f8c2dfe502336fc66e6cb8ea4391900b7950239910b0efe382ed11d059af64d3e6f0f071daf2c1e8f
        EAP-Message =
0x6039e2fa36531339d45e262bdb3da814bd32eb180328520471e5ab333de138bb073684629c79ea1630f45fc02be8716be4f90203010001a3533051300f0603551d130101ff040530030101ff301d0603551d0e04160414c07a98688d89fbab05640c117daa7d65b8cacc4e301f0603551d23041830168014c07a98688d89fbab05640c117daa7d65b8cacc4e300d06092a864886f70d0101050500038201010035e3296ae52f5d548e2950949f991a14e48f782a6294a227679ed0cf1a5e47e9c1b2a4cfdd411a054e9b4bee4a6f5552b324a1370aeb64762a2e2cf3fd3b7590bffa71d8c73d37d2b5059562b9a6de893d367b38774897aca6208f2ea6
        EAP-Message = 0xc90cc2b2994500c7
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772351156e31559fe392aa31ada6
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=244, length=163
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024800061900
        State = 0x555d772351156e31559fe392aa31ada6
        Message-Authenticator = 0x475bb671a8da18583904dbdc552480d7
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 72 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 72 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake fragment handler
[peap] eaptls_verify returned 1
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 244 to 192.168.100.110 port 54618
        EAP-Message =
0x014901fa1900ce11512222e0a5eab615480964ea5e4f74f7053ec78a520cdb15b4bd6d9be5c6b15468a9e36990b69aa50fb8b93f207dae4ab5b89ce41db6abe694a5c1c783addbf527870e046cd5ffdda05ded8752b72b1502ae39a66a74e9dac4e7bc4d341ea95c4d335f92092f88665d7797c71d7613a9d5e5f116091135d5acdb2471702c98560bd917b4d1e3512b5e75e8d5d0dc4f34edc2056680a1cbe633160301014b0c0001470300174104adcf705966a6858a4f78be47015abe4adba8f609377cbe766c2b26c88464db92bc6621a951971b49896715e02a884997a0a36b8ad87dea5ff43d48e752e9f02c0100a88abc45fc54f19099ac6625
        EAP-Message =
0x3ed002e77d05b79d74f7306dbf23e68ddecaa6b9b552fa25fdc98a4030df327bc6a162a69f41bd892919e98db8975d703657a6e54780d7663a6bd3c4d3b78f707d4c9a8b1c84fa1b788f020d6fbf9293f8ad1ca07eea09a081bd0bce3156c1d750ae24f5707e36502b246a77664d3aebb74f43022035fe329ee4273d651a214cc5961e5d51f0b071c15a13a126cbaeeedf2e317bedc197135dad4e02a91dcc954cb3fc840bab7df73d28378c8835cb927efd97bc089f7a3951f0bc254bc66f43808adec235a533c5e0eda359ccec012ee1f4d01e4cbbca82b3dc4cd152e0d4c088009be9701ea70b8c0005610727cf913d6d297316030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772350146e31559fe392aa31ada6
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=245, length=301
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x0249009019800000008616030100461000004241040100392b69186727a83e1c0fee8f4fae799b87b8074213b3581991397f451e33788ccb83de581d363adb7d64e5e552a7283962e95e148587b21789a874edfb801403010001011603010030f7b24b9c0eb9516c0bf7fe7475d49ba6810157504129548cc2d63a5012b5f6bf71ec43d347d6d8fde451c95ee74513e1
        State = 0x555d772350146e31559fe392aa31ada6
        Message-Authenticator = 0xb10cc11ff7be4967c693d1364872e71f
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 73 length 144
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 73 length 144
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
  TLS Length 134
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
[peap]     TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap]     TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap]     TLS_accept: SSLv3 write finished A
[peap]     TLS_accept: SSLv3 flush data
[peap]     (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 245 to 192.168.100.110 port 54618
        EAP-Message =
0x014a004119001403010001011603010030a82cd3e336499dfddf554fa3c77f5f1f7bdf4bbb9c9311319f25b621878f139ad20eb69a8880707ff35d117a9bb3de2f
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772353176e31559fe392aa31ada6
Finished request 6.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=246, length=163
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message = 0x024a00061900
        State = 0x555d772353176e31559fe392aa31ada6
        Message-Authenticator = 0x906676332f4572cf472c543e7f6c5f34
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 74 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 74 length 6
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 246 to 192.168.100.110 port 54618
        EAP-Message =
0x014b002b190017030100201202c7f9d385135fc348829340d320e0e07bf195a3a99914ca60d5f9aa70fc30
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d772352166e31559fe392aa31ada6
Finished request 7.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=247, length=237
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x024b005019001703010020d677482105ba92a65b9765fab3463503eb3f14c2b373ed7b1b47041545928b9a1703010020baadd37ecdc24ba0786ef5e6aa44c2cf0c2953c55272f076ae5885e5a3244878
        State = 0x555d772352166e31559fe392aa31ada6
        Message-Authenticator = 0x1b6e0a19f4ffd861c985327f35b3b1e6
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 75 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 75 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - test
[peap] Got inner identity 'test'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
        EAP-Message = 0x024b00090174657374
server  {
[peap] Setting User-Name to test
Sending tunneled request
        EAP-Message = 0x024b00090174657374
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
server inner-tunnel {
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 75 length 9
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
rlm_sql (sql): Reserving sql socket id: 28
[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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'test'           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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'test'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username = 'test'
      ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
  WHERE username = 'test'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'base'
ORDER BY id
[sql] User found in group base
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'base'
ORDER BY id
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'Agenti'
ORDER BY id
[sql] User found in group Agenti
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'Agenti'
ORDER BY id
rlm_sql (sql): Released sql socket id: 28
++[sql] = ok
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] EAP Identity
[eap] processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] = handled
+} # group authenticate = handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message =
0x014c001e1a014c0019103dce9782bee48bf472c7f5425087c72674657374
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xabf8cadfabb4d01eb3c0f093c6a4eb71
[peap] Got tunneled reply RADIUS code Access-Challenge
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message =
0x014c001e1a014c0019103dce9782bee48bf472c7f5425087c72674657374
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xabf8cadfabb4d01eb3c0f093c6a4eb71
[peap] Got tunneled Access-Challenge
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 247 to 192.168.100.110 port 54618
        EAP-Message =
0x014c003b190017030100300888ca445b54083a3b0d20c7409ca86b81b08a088fc85af0b8e1c3f3bbf501224221ab6417f4383cc8135873b72ce6c4
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d77235d116e31559fe392aa31ada6
Finished request 8.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=248, length=285
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x024c0080190017030100209c5ee94571d29fe6a2846a6593433afffef5dbfff55d5a729d72bfdc9089d9e1170301005037b838ce5126bbea7da947a318386ee0290b70146f670ca2d87ec76cf0cf8bedee77d12d8e2548dbc394e15fb89b0207c738bb15f52d0f2b3953b0da65ad375cd2ac8242f81f5db3d6144db5af98fd4c
        State = 0x555d77235d116e31559fe392aa31ada6
        Message-Authenticator = 0x55034d99c0740d9e908987b966cea09b
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 76 length 128
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 76 length 128
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
        EAP-Message =
0x024c003f1a024c003a316f8d134fc8ddf47cd560147345e05f0600000000000000002e8a3c336070d2f66089a7666d32dacfb893153f577573400074657374
server  {
[peap] Setting User-Name to test
Sending tunneled request
        EAP-Message =
0x024c003f1a024c003a316f8d134fc8ddf47cd560147345e05f0600000000000000002e8a3c336070d2f66089a7666d32dacfb893153f577573400074657374
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "test"
        State = 0xabf8cadfabb4d01eb3c0f093c6a4eb71
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
server inner-tunnel {
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 76 length 63
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
rlm_sql (sql): Reserving sql socket id: 27
[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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'test'           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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'test'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username = 'test'
      ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
  WHERE username = 'test'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'base'
ORDER BY id
[sql] User found in group base
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'base'
ORDER BY id
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'Agenti'
ORDER BY id
[sql] User found in group Agenti
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'Agenti'
ORDER BY id
rlm_sql (sql): Released sql socket id: 27
++[sql] = ok
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] # Executing group from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
[mschapv2] +group MS-CHAP {
[mschap] Creating challenge hash with username: test
[mschap] Client is using MS-CHAPv2 for test, we need NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] = ok
+} # group MS-CHAP = ok
MSCHAP Success
++[eap] = handled
+} # group authenticate = handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message =
0x014d00331a034c002e533d39413043324530443931384344393930353536324330383445454435434346314638413539323237
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xabf8cadfaab5d01eb3c0f093c6a4eb71
[peap] Got tunneled reply RADIUS code Access-Challenge
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        EAP-Message =
0x014d00331a034c002e533d39413043324530443931384344393930353536324330383445454435434346314638413539323237
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xabf8cadfaab5d01eb3c0f093c6a4eb71
[peap] Got tunneled Access-Challenge
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 248 to 192.168.100.110 port 54618
        EAP-Message =
0x014d005b190017030100503a5f1aa21b43edc9ac6228c19254e32b56c0843e207ccfdb7a92d05145b2f18aa7e570613d528decece331c8819f81ddac7d9ce6cc45821d18d68241ecf6142e6891dbbcb3a16172c6ff46bdf3f1b608
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d77235c106e31559fe392aa31ada6
Finished request 9.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=249, length=237
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x024d005019001703010020e1e400fee1a49c5d87d16d58eace64f5ba559b95b88393ac1d00da065656e2f417030100205c832cca3a5a18153b722896597bd88692f9712f857b76863fe15e2107b2ff72
        State = 0x555d77235c106e31559fe392aa31ada6
        Message-Authenticator = 0x04466dfae40bf25aeb60fae97dec832c
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 77 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 77 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state phase2
[peap] EAP type mschapv2
[peap] Got tunneled request
        EAP-Message = 0x024d00061a03
server  {
[peap] Setting User-Name to test
Sending tunneled request
        EAP-Message = 0x024d00061a03
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "test"
        State = 0xabf8cadfaab5d01eb3c0f093c6a4eb71
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
server inner-tunnel {
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authorize {
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 77 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] = updated
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
rlm_sql (sql): Reserving sql socket id: 26
[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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = 'test'           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 = 'test'           ORDER BY id
rlm_sql_mysql: query:  SELECT id, username, attribute, value, op
FROM radreply           WHERE username = 'test'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username = 'test'
      ORDER BY priority
rlm_sql_mysql: query:  SELECT groupname           FROM radusergroup
  WHERE username = 'test'           ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'base'
ORDER BY id
[sql] User found in group base
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'base'           ORDER BY
id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'base'
ORDER BY id
[sql]   expand: SELECT id, groupname, attribute,           Value, op
    FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
  FROM radgroupcheck           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           Value, op
          FROM radgroupcheck           WHERE groupname = 'Agenti'
ORDER BY id
[sql] User found in group Agenti
[sql]   expand: SELECT id, groupname, attribute,           value, op
    FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
  FROM radgroupreply           WHERE groupname = 'Agenti'           ORDER
BY id
rlm_sql_mysql: query:  SELECT id, groupname, attribute,           value, op
          FROM radgroupreply           WHERE groupname = 'Agenti'
ORDER BY id
rlm_sql (sql): Released sql socket id: 26
++[sql] = ok
[pap] WARNING: Auth-Type already set.  Not setting to PAP
++[pap] = noop
+} # group authorize = updated
Found Auth-Type = EAP
# Executing group from file /usr/local/etc/raddb/sites-enabled/inner-tunnel
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
# Executing section session from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
+group session {
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
[sql]   expand: SELECT COUNT(*)                              FROM radacct
                           WHERE username = '%{SQL-User-Name}'
              AND acctstoptime IS NULL -> SELECT COUNT(*)
           FROM radacct                              WHERE username =
'test'                           AND acctstoptime IS NULL
rlm_sql (sql): Reserving sql socket id: 25
rlm_sql_mysql: query:  SELECT COUNT(*)                              FROM
radacct                              WHERE username = 'test'
         AND acctstoptime IS NULL
rlm_sql (sql): Released sql socket id: 25
++[sql] = ok
+} # group session = ok
# Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
+group post-auth {
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
[sql]   expand: %{User-Password} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} ->
[sql]   expand: INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                    '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
        (username, pass, reply, authdate)                           VALUES
(                           'test',                           '',
                'Access-Accept', '2015-08-18 10:40:54')
[sql]   expand: /usr/local/var/log/radius/sqltrace.sql ->
/usr/local/var/log/radius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
              (username, pass, reply, authdate)
VALUES (                           'test',                           '',
                        'Access-Accept', '2015-08-18 10:40:54')
rlm_sql (sql): Reserving sql socket id: 24
rlm_sql_mysql: query:  INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                    'test',                           '',
        'Access-Accept', '2015-08-18 10:40:54')
rlm_sql (sql): Released sql socket id: 24
++[sql] = ok
+} # group post-auth = ok
} # server inner-tunnel
[peap] Got tunneled reply code 2
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        MS-MPPE-Encryption-Policy = 0x00000002
        MS-MPPE-Encryption-Types = 0x00000004
        MS-MPPE-Send-Key = 0x01c5ebe9fad40e0563466bbdf1846f1e
        MS-MPPE-Recv-Key = 0xfd2242005fe30e9f2804ae4aa2adb62b
        EAP-Message = 0x034d0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "test"
[peap] Got tunneled reply RADIUS code Access-Accept
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        MS-MPPE-Encryption-Policy = 0x00000002
        MS-MPPE-Encryption-Types = 0x00000004
        MS-MPPE-Send-Key = 0x01c5ebe9fad40e0563466bbdf1846f1e
        MS-MPPE-Recv-Key = 0xfd2242005fe30e9f2804ae4aa2adb62b
        EAP-Message = 0x034d0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "test"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
[peap] Saving tunneled attributes for later
++[eap] = handled
+} # group authenticate = handled
Sending Access-Challenge of id 249 to 192.168.100.110 port 54618
        EAP-Message =
0x014e002b1900170301002015d6e9727357e69f0fe77e96e4843eb7c2c263cc8269b59d6c3e3376339e2d74
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x555d77235f136e31559fe392aa31ada6
Finished request 10.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 192.168.100.110 port 54618,
id=250, length=237
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 0Mbps 802.11b"
        EAP-Message =
0x024e005019001703010020a37daa262ddc85cc10869904030d772521beaed4abad8ffb3d87a02335029eb91703010020f6618b025780ee4010b30c442033b30a9b3765bc13ecbf3a1fcbfb561fb9fc49
        State = 0x555d77235f136e31559fe392aa31ada6
        Message-Authenticator = 0x7df2a0bf7d96ff1eaf8f0ff8dc44e905
# Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
+group authorize {
[eap] EAP packet type response id 78 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
++[preprocess] = ok
++[chap] = noop
++[mschap] = noop
[eap] EAP packet type response id 78 length 80
[eap] Continuing tunnel setup.
++[eap] = ok
+} # group authorize = ok
Found Auth-Type = EAP
Found Auth-Type = EAP
Warning:  Found 2 auth-types on request for user 'test'
# Executing group from file /usr/local/etc/raddb/sites-enabled/default
+group authenticate {
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Peap state send tlv success
[peap] Received EAP-TLV response.
[peap] Success
[peap] Using saved attributes from the original Access-Accept
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        User-Name = "test"
[eap] Freeing handler
++[eap] = ok
+} # group authenticate = ok
# Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/default
+group post-auth {
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
[sql]   expand: %{User-Password} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} ->
[sql]   expand: INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                    '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth
        (username, pass, reply, authdate)                           VALUES
(                           'test',                           '',
                'Access-Accept', '2015-08-18 10:40:54')
[sql]   expand: /usr/local/var/log/radius/sqltrace.sql ->
/usr/local/var/log/radius/sqltrace.sql
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
              (username, pass, reply, authdate)
VALUES (                           'test',                           '',
                        'Access-Accept', '2015-08-18 10:40:54')
rlm_sql (sql): Reserving sql socket id: 23
rlm_sql_mysql: query:  INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                    'test',                           '',
        'Access-Accept', '2015-08-18 10:40:54')
rlm_sql (sql): Released sql socket id: 23
++[sql] = ok
++[exec] = noop
+} # group post-auth = ok
Sending Access-Accept of id 250 to 192.168.100.110 port 54618
        Tunnel-Private-Group-Id:0 = "50"
        Tunnel-Type:0 = VLAN
        Tunnel-Medium-Type:0 = IEEE-802
        User-Name = "test"
        MS-MPPE-Recv-Key =
0x7a5b3fb15cae164364eac83736404274144bfe89d11cddddbb755ce58f94641c
        MS-MPPE-Send-Key =
0x39282d41c4abf064cc0e8bb6a9ae82af9d9a6cca7daf844b0b0addcff709286c
        EAP-Message = 0x034e0004
        Message-Authenticator = 0x00000000000000000000000000000000
Finished request 11.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Accounting-Request packet from host 192.168.100.110 port 54860,
id=251, length=159
        Acct-Session-Id = "55CE1818-00000024"
        Acct-Status-Type = Start
        Acct-Authentic = RADIUS
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        Vendor-29671-Attr-1 = 0x53797345646974
        NAS-Port = 0
        Called-Station-Id = "00-18-0A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        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 {
WARNING: Unknown module "expr" in string expansion "%"
++} # update request = noop
[acct_unique] WARNING: Attribute Event-Timestamp was not found in request,
unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute NAS-Identifier was not found in request,
unique ID MAY be inconsistent
[acct_unique] Hashing ',NAS-Port = 0,,NAS-IP-Address =
192.168.100.110,Acct-Session-Id = "55CE1818-00000024",User-Name = "test"'
[acct_unique] Acct-Unique-Session-ID = "510f892f8ab18937".
++[acct_unique] = ok
+} # group preacct = ok
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+group accounting {
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
[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}',
[sql]   expand: /usr/local/var/log/radius/sqltrace.sql ->
/usr/local/var/log/radius/sqltrace.sql
rlm_sql (sql): Reserving sql socket id: 22
rlm_sql_mysql: 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
('55CE1818-00000024', '510f892f8ab18937',              'test',
 '', '192.168.100.110', '0',              'Wireless-802.11', '2015-08-18
10:40:54', NULL,              '0', 'RADIUS', 'CONNECT 0Mbps 802.11b',
       '', '0', '0',              '00-18-0A-7A-91-3C:Netweek',
'78-4B-87-67-A9-1C', '',              '', '', '',              '0', '0', '')
rlm_sql (sql): Released sql socket id: 22
++[sql] = ok
++? if (noop)
? Evaluating (noop) -> FALSE
++? if (noop) -> FALSE
++[exec] = noop
[attr_filter.accounting_response]       expand: %{User-Name} -> test
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 251 to 192.168.100.110 port 54860
Finished request 12.
Cleaning up request 12 ID 251 with timestamp +168
Going to the next request
Waking up in 4.8 seconds.
Cleaning up request 0 ID 239 with timestamp +168
Cleaning up request 1 ID 240 with timestamp +168
Cleaning up request 2 ID 241 with timestamp +168
Cleaning up request 3 ID 242 with timestamp +168
Cleaning up request 4 ID 243 with timestamp +168
Cleaning up request 5 ID 244 with timestamp +168
Cleaning up request 6 ID 245 with timestamp +168
Cleaning up request 7 ID 246 with timestamp +168
Cleaning up request 8 ID 247 with timestamp +168
Cleaning up request 9 ID 248 with timestamp +168
Cleaning up request 10 ID 249 with timestamp +168
Cleaning up request 11 ID 250 with timestamp +168
Ready to process requests.




----------------------------------------------------------------------------------------------------------------------------------------

subsequent connections:

rad_recv: Accounting-Request packet from host 192.168.100.110 port 47053,
id=90, length=165
        Acct-Session-Id = "55CE1818-00000027"
        Acct-Status-Type = Start
        Acct-Authentic = RADIUS
        User-Name = "test"
        NAS-IP-Address = 192.168.100.110
        Vendor-29671-Attr-1 = 0x53797345646974
        NAS-Port = 0
        Called-Station-Id = "02-18-1A-7A-91-3C:Netweek"
        Calling-Station-Id = "78-4B-87-67-A9-1C"
        Framed-IP-Address = 192.168.1.33
        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 {
WARNING: Unknown module "expr" in string expansion "%"
++} # update request = noop
[acct_unique] WARNING: Attribute Event-Timestamp was not found in request,
unique ID MAY be inconsistent
[acct_unique] WARNING: Attribute NAS-Identifier was not found in request,
unique ID MAY be inconsistent
[acct_unique] Hashing ',NAS-Port = 0,,NAS-IP-Address =
192.168.100.110,Acct-Session-Id = "55CE1818-00000027",User-Name = "test"'
[acct_unique] Acct-Unique-Session-ID = "e8f0af133522780c".
++[acct_unique] = ok
+} # group preacct = ok
# Executing section accounting from file
/usr/local/etc/raddb/sites-enabled/default
+group accounting {
[sql]   expand: %{User-Name} -> test
[sql] sql_set_user escaped user --> 'test'
[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}',
[sql]   expand: /usr/local/var/log/radius/sqltrace.sql ->
/usr/local/var/log/radius/sqltrace.sql
rlm_sql (sql): Reserving sql socket id: 19
rlm_sql_mysql: 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
('55CE1818-00000027', 'e8f0af133522780c',              'test',
 '', '192.168.100.110', '0',              'Wireless-802.11', '2015-08-18
10:44:20', NULL,              '0', 'RADIUS', 'CONNECT 0Mbps 802.11b',
       '', '0', '0',              '02-18-1A-7A-91-3C:Netweek',
'78-4B-87-67-A9-1C', '',              '', '', '192.168.1.33',
 '0', '0', '')
rlm_sql (sql): Released sql socket id: 19
++[sql] = ok
++? if (noop)
? Evaluating (noop) -> FALSE
++? if (noop) -> FALSE
++[exec] = noop
[attr_filter.accounting_response]       expand: %{User-Name} -> test
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 90 to 192.168.100.110 port 47053
Finished request 15.
Cleaning up request 15 ID 90 with timestamp +374
Going to the next request
Ready to process requests.




Riccardo Locatelli


More information about the Freeradius-Users mailing list