freeradius vlan assigment with two ldap group

15 Sep 2017


      Hello,
I have trouble assigning the  vlan to users in different groups. If I 
have one group and if the user is in this group gets a VLAN 200. If  
another user is in another group (add another entry in the users file 
with the group and vlan), it does not log on or continue to receive the 
vlan 200 and I want it to get vlan 216. Below debug with login.


Users are sure to exist and in the appropriate groups


Fri Sep 15 09:07:01 2017 : Info: freeradius: FreeRADIUS Version 2.2.5, 
for host x86_64-pc-linux-gnu, built on Aug 10 2017 at 07:25:15
Fri Sep 15 09:07:01 2017 : Debug: Server was built with:
Fri Sep 15 09:07:01 2017 : Debug:   accounting
Fri Sep 15 09:07:01 2017 : Debug:   authentication
Fri Sep 15 09:07:01 2017 : Debug:  WITH_DHCP
Fri Sep 15 09:07:01 2017 : Debug:  WITH_VMPS
Fri Sep 15 09:07:01 2017 : Debug: Server core libs:
Fri Sep 15 09:07:01 2017 : Debug:   ssl: OpenSSL 1.0.1t  3 May 2016
Fri Sep 15 09:07:01 2017 : Info: Copyright (C) 1999-2013 The FreeRADIUS 
server project and contributors.
Fri Sep 15 09:07:01 2017 : Info: There is NO warranty; not even for 
MERCHANTABILITY or FITNESS FOR A
Fri Sep 15 09:07:01 2017 : Info: PARTICULAR PURPOSE.
Fri Sep 15 09:07:01 2017 : Info: You may redistribute copies of 
FreeRADIUS under the terms of the
Fri Sep 15 09:07:01 2017 : Info: GNU General Public License.
Fri Sep 15 09:07:01 2017 : Info: For more information about these 
matters, see the file named COPYRIGHT.
Fri Sep 15 09:07:01 2017 : Info: Starting - reading configuration files ...
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/radiusd.conf
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/proxy.conf
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/clients.conf
Fri Sep 15 09:07:01 2017 : Debug: including files in directory 
/etc/freeradius/modules/
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/attr_filter
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/pap
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/radrelay
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/mschap
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/etc_group
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/sradutmp
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/detail.example.com
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/ippool
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/always
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/rediswho
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/smsotp
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/chap
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/exec
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/replicate
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/attr_rewrite
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/checkval
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/krb5
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/smbpasswd
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/sqlcounter_expire_on_login
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/counter
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/detail
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/inner-eap
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/realm
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/sql_log
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/perl
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/redis
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/passwd
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/radutmp
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/digest
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/preprocess
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/ntlm_auth
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/mac2vlan
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/detail.log
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/policy
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/acct_unique
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/dhcp_sqlippool
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/dynamic_clients
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/mac2ip
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/soh
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/ldap
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/wimax
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/expiration
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/pam
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/logintime
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/files
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/cache
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/unix
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/echo
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/otp
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/opendirectory
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/expr
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/cui
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/modules/linelog
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/eap.conf
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/policy.conf
Fri Sep 15 09:07:01 2017 : Debug: including files in directory 
/etc/freeradius/sites-enabled/
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:01 2017 : Debug: including configuration file 
/etc/freeradius/sites-enabled/default.orig
Fri Sep 15 09:07:01 2017 : Debug: main {
Fri Sep 15 09:07:01 2017 : Debug:     user = "freerad"
Fri Sep 15 09:07:01 2017 : Debug:     group = "freerad"
Fri Sep 15 09:07:01 2017 : Debug:     allow_core_dumps = no
Fri Sep 15 09:07:01 2017 : Debug: }
Fri Sep 15 09:07:01 2017 : Debug: including dictionary file 
/etc/freeradius/dictionary
Fri Sep 15 09:07:01 2017 : Debug: main {
Fri Sep 15 09:07:01 2017 : Debug:     name = "freeradius"
Fri Sep 15 09:07:01 2017 : Debug:     prefix = "/usr"
Fri Sep 15 09:07:01 2017 : Debug:     localstatedir = "/var"
Fri Sep 15 09:07:01 2017 : Debug:     sbindir = "/usr/sbin"
Fri Sep 15 09:07:01 2017 : Debug:     logdir = "/var/log/freeradius"
Fri Sep 15 09:07:01 2017 : Debug:     run_dir = "/var/run/freeradius"
Fri Sep 15 09:07:01 2017 : Debug:     libdir = "/usr/lib/freeradius"
Fri Sep 15 09:07:01 2017 : Debug:     radacctdir = 
"/var/log/freeradius/radacct"
Fri Sep 15 09:07:01 2017 : Debug:     hostname_lookups = no
Fri Sep 15 09:07:01 2017 : Debug:     max_request_time = 30
Fri Sep 15 09:07:01 2017 : Debug:     cleanup_delay = 5
Fri Sep 15 09:07:01 2017 : Debug:     max_requests = 1024
Fri Sep 15 09:07:01 2017 : Debug:     pidfile = 
"/var/run/freeradius/freeradius.pid"
Fri Sep 15 09:07:01 2017 : Debug:     checkrad = "/usr/sbin/checkrad"
Fri Sep 15 09:07:01 2017 : Debug:     debug_level = 0
Fri Sep 15 09:07:01 2017 : Debug:     proxy_requests = yes
Fri Sep 15 09:07:01 2017 : Debug:  log {
Fri Sep 15 09:07:01 2017 : Debug:      stripped_names = no
Fri Sep 15 09:07:01 2017 : Debug:      auth = no
Fri Sep 15 09:07:01 2017 : Debug:      auth_badpass = no
Fri Sep 15 09:07:01 2017 : Debug:      auth_goodpass = no
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  security {
Fri Sep 15 09:07:01 2017 : Debug:      max_attributes = 200
Fri Sep 15 09:07:01 2017 : Debug:      reject_delay = 1
Fri Sep 15 09:07:01 2017 : Debug:      status_server = yes
Fri Sep 15 09:07:01 2017 : Debug:      allow_vulnerable_openssl = no
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug: }
Fri Sep 15 09:07:01 2017 : Debug: radiusd: #### Loading Realms and Home 
Servers ####
Fri Sep 15 09:07:01 2017 : Debug:  proxy server {
Fri Sep 15 09:07:01 2017 : Debug:      retry_delay = 5
Fri Sep 15 09:07:01 2017 : Debug:      retry_count = 3
Fri Sep 15 09:07:01 2017 : Debug:      default_fallback = no
Fri Sep 15 09:07:01 2017 : Debug:      dead_time = 120
Fri Sep 15 09:07:01 2017 : Debug:      wake_all_if_all_dead = no
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  home_server radius149.156.2.40 {
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = 149.156.2.40
Fri Sep 15 09:07:01 2017 : Debug:      port = 1812
Fri Sep 15 09:07:01 2017 : Debug:      type = "auth"
Fri Sep 15 09:07:01 2017 : Debug:      secret = 
"CyirkOswir23vyaw2Flymmy7g2yik4shJediajWog"
Fri Sep 15 09:07:01 2017 : Debug:      response_window = 20
Fri Sep 15 09:07:01 2017 : Debug:      max_outstanding = 65536
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = yes
Fri Sep 15 09:07:01 2017 : Debug:      zombie_period = 40
Fri Sep 15 09:07:01 2017 : Debug:      status_check = "status-server"
Fri Sep 15 09:07:01 2017 : Debug:      ping_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      check_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      num_answers_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      num_pings_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      revive_interval = 300
Fri Sep 15 09:07:01 2017 : Debug:      status_check_timeout = 4
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  home_server radius149.156.2.66 {
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = 149.156.2.66
Fri Sep 15 09:07:01 2017 : Debug:      port = 1812
Fri Sep 15 09:07:01 2017 : Debug:      type = "auth"
Fri Sep 15 09:07:01 2017 : Debug:      secret = 
"CyirkOswir23vyaw2Flymmy7g2yik4shJediajWog"
Fri Sep 15 09:07:01 2017 : Debug:      response_window = 20
Fri Sep 15 09:07:01 2017 : Debug:      max_outstanding = 65536
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = yes
Fri Sep 15 09:07:01 2017 : Debug:      zombie_period = 40
Fri Sep 15 09:07:01 2017 : Debug:      status_check = "status-server"
Fri Sep 15 09:07:01 2017 : Debug:      ping_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      check_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      num_answers_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      num_pings_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      revive_interval = 300
Fri Sep 15 09:07:01 2017 : Debug:      status_check_timeout = 4
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  home_server localhost {
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = 127.0.0.1
Fri Sep 15 09:07:01 2017 : Debug:      port = 1812
Fri Sep 15 09:07:01 2017 : Debug:      type = "auth"
Fri Sep 15 09:07:01 2017 : Debug:      secret = "testing123"
Fri Sep 15 09:07:01 2017 : Debug:      response_window = 20
Fri Sep 15 09:07:01 2017 : Debug:      no_response_fail = no
Fri Sep 15 09:07:01 2017 : Debug:      max_outstanding = 65536
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = yes
Fri Sep 15 09:07:01 2017 : Debug:      zombie_period = 40
Fri Sep 15 09:07:01 2017 : Debug:      status_check = "status-server"
Fri Sep 15 09:07:01 2017 : Debug:      ping_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      check_interval = 30
Fri Sep 15 09:07:01 2017 : Debug:      num_answers_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      num_pings_to_alive = 3
Fri Sep 15 09:07:01 2017 : Debug:      revive_interval = 120
Fri Sep 15 09:07:01 2017 : Debug:      status_check_timeout = 4
Fri Sep 15 09:07:01 2017 : Debug:   coa {
Fri Sep 15 09:07:01 2017 : Debug:       irt = 2
Fri Sep 15 09:07:01 2017 : Debug:       mrt = 16
Fri Sep 15 09:07:01 2017 : Debug:       mrc = 5
Fri Sep 15 09:07:01 2017 : Debug:       mrd = 30
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  realm NULL {
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  realm LOCAL {
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  realm mydomain.com {
Fri Sep 15 09:07:01 2017 : Debug:     authhost = LOCAL
Fri Sep 15 09:07:01 2017 : Debug:     accthost = LOCAL
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  home_server_pool CYFRONET_pool {
Fri Sep 15 09:07:01 2017 : Debug:     type = fail-over
Fri Sep 15 09:07:01 2017 : Debug:     home_server = radius149.156.2.66
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  realm DEFAULT {
Fri Sep 15 09:07:01 2017 : Debug:     auth_pool = CYFRONET_pool
Fri Sep 15 09:07:01 2017 : Debug:     nostrip
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug: radiusd: #### Loading Clients ####
Fri Sep 15 09:07:01 2017 : Debug:  client localhost {
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = 127.0.0.1
Fri Sep 15 09:07:01 2017 : Debug:      netmask = 32
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = no
Fri Sep 15 09:07:01 2017 : Debug:      secret = "testing123"
Fri Sep 15 09:07:01 2017 : Debug:      shortname = "localhost"
Fri Sep 15 09:07:01 2017 : Debug:      nastype = "other"
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  client 10.24.100.41 {
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = 10.24.100.41
Fri Sep 15 09:07:01 2017 : Debug:      netmask = 32
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = no
Fri Sep 15 09:07:01 2017 : Debug:      secret = "vFayVjKTby3o"
Fri Sep 15 09:07:01 2017 : Debug:      nastype = "cisco"
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  client 149.156.2.40 {
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = no
Fri Sep 15 09:07:01 2017 : Debug:      secret = 
"CyirkOswir23vyaw2Flymmy7g2yik4shJediajWog"
Fri Sep 15 09:07:01 2017 : Debug:      nastype = "other"
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug:  client 149.156.2.66 {
Fri Sep 15 09:07:01 2017 : Debug: require_message_authenticator = no
Fri Sep 15 09:07:01 2017 : Debug:      secret = 
"CyirkOswir23vyaw2Flymmy7g2yik4shJediajWog"
Fri Sep 15 09:07:01 2017 : Debug:      nastype = "other"
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug: radiusd: #### Instantiating modules ####
Fri Sep 15 09:07:01 2017 : Debug:  instantiate {
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_exec, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_exec
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "exec" 
from file /etc/freeradius/modules/exec
Fri Sep 15 09:07:01 2017 : Debug:   exec {
Fri Sep 15 09:07:01 2017 : Debug:       wait = no
Fri Sep 15 09:07:01 2017 : Debug:       input_pairs = "request"
Fri Sep 15 09:07:01 2017 : Debug:       shell_escape = yes
Fri Sep 15 09:07:01 2017 : Debug:       timeout = 10
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_expr, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_expr
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "expr" 
from file /etc/freeradius/modules/expr
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_expiration, checking 
if it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_expiration
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"expiration" from file /etc/freeradius/modules/expiration
Fri Sep 15 09:07:01 2017 : Debug:   expiration {
Fri Sep 15 09:07:01 2017 : Debug:       reply-message = "Password Has 
Expired  "
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_logintime, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_logintime
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"logintime" from file /etc/freeradius/modules/logintime
Fri Sep 15 09:07:01 2017 : Debug:   logintime {
Fri Sep 15 09:07:01 2017 : Debug:       reply-message = "You are calling 
outside your allowed timespan  "
Fri Sep 15 09:07:01 2017 : Debug:       minimum-timeout = 60
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:  }
Fri Sep 15 09:07:01 2017 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Sep 15 09:07:01 2017 : Debug: server { # from file ?
Fri Sep 15 09:07:01 2017 : Debug:  modules {
Fri Sep 15 09:07:01 2017 : Debug:   Module: Creating Auth-Type = digest
Fri Sep 15 09:07:01 2017 : Debug:   Module: Creating Auth-Type = LDAP
Fri Sep 15 09:07:01 2017 : Debug:   Module: Creating Post-Auth-Type = REJECT
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_pap, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_pap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "pap" 
from file /etc/freeradius/modules/pap
Fri Sep 15 09:07:01 2017 : Debug:   pap {
Fri Sep 15 09:07:01 2017 : Debug:       encryption_scheme = "auto"
Fri Sep 15 09:07:01 2017 : Debug:       auto_header = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_chap, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_chap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "chap" 
from file /etc/freeradius/modules/chap
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_mschap, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_mschap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "mschap" 
from file /etc/freeradius/modules/mschap
Fri Sep 15 09:07:01 2017 : Debug:   mschap {
Fri Sep 15 09:07:01 2017 : Debug:       use_mppe = no
Fri Sep 15 09:07:01 2017 : Debug:       require_encryption = no
Fri Sep 15 09:07:01 2017 : Debug:       require_strong = no
Fri Sep 15 09:07:01 2017 : Debug:       with_ntdomain_hack = no
Fri Sep 15 09:07:01 2017 : Debug:       ntlm_auth = "/usr/bin/ntlm_auth 
--request-nt-key --username=%{Stripped-User-Name:-%{User-Name:-None}} 
--challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}"
Fri Sep 15 09:07:01 2017 : Debug:       allow_retry = yes
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_digest, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_digest
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "digest" 
from file /etc/freeradius/modules/digest
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_ldap, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_ldap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "ldap" 
from file /etc/freeradius/modules/ldap
Fri Sep 15 09:07:01 2017 : Debug:   ldap {
Fri Sep 15 09:07:01 2017 : Debug:       server = "ldap1.mydomain.com"
Fri Sep 15 09:07:01 2017 : Debug:       port = 389
Fri Sep 15 09:07:01 2017 : Debug:       password = "rad--IJP--02"
Fri Sep 15 09:07:01 2017 : Debug:       expect_password = yes
Fri Sep 15 09:07:01 2017 : Debug:       identity = 
"cn=freeradius,ou=services,dc=ijp,dc=pan,dc=local"
Fri Sep 15 09:07:01 2017 : Debug:       net_timeout = 1
Fri Sep 15 09:07:01 2017 : Debug:       timeout = 4
Fri Sep 15 09:07:01 2017 : Debug:       timelimit = 3
Fri Sep 15 09:07:01 2017 : Debug:       max_uses = 0
Fri Sep 15 09:07:01 2017 : Debug:       tls_mode = no
Fri Sep 15 09:07:01 2017 : Debug:       start_tls = no
Fri Sep 15 09:07:01 2017 : Debug:       tls_require_cert = "allow"
Fri Sep 15 09:07:01 2017 : Debug:    tls {
Fri Sep 15 09:07:01 2017 : Debug:        start_tls = no
Fri Sep 15 09:07:01 2017 : Debug:        require_cert = "allow"
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:       basedn = "dc=ijp,dc=pan,dc=local"
Fri Sep 15 09:07:01 2017 : Debug:       filter = 
"(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})"
Fri Sep 15 09:07:01 2017 : Debug:       base_filter = 
"(objectclass=radiusprofile)"
Fri Sep 15 09:07:01 2017 : Debug:       auto_header = no
Fri Sep 15 09:07:01 2017 : Debug:       access_attr_used_for_allow = yes
Fri Sep 15 09:07:01 2017 : Debug:       chase_referrals = yes
Fri Sep 15 09:07:01 2017 : Debug:       rebind = yes
Fri Sep 15 09:07:01 2017 : Debug:       groupname_attribute = "cn"
Fri Sep 15 09:07:01 2017 : Debug:       groupmembership_filter = 
"(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn})))"
Fri Sep 15 09:07:01 2017 : Debug:       groupmembership_attribute = 
"memberOf"
Fri Sep 15 09:07:01 2017 : Debug:       dictionary_mapping = 
"/etc/freeradius/ldap.attrmap"
Fri Sep 15 09:07:01 2017 : Debug:       ldap_debug = 0
Fri Sep 15 09:07:01 2017 : Debug:       ldap_connections_number = 5
Fri Sep 15 09:07:01 2017 : Debug:       compare_check_items = no
Fri Sep 15 09:07:01 2017 : Debug:       do_xlat = yes
Fri Sep 15 09:07:01 2017 : Debug:       edir_account_policy_check = no
Fri Sep 15 09:07:01 2017 : Debug:       set_auth_type = yes
Fri Sep 15 09:07:01 2017 : Debug:    keepalive {
Fri Sep 15 09:07:01 2017 : Debug:        idle = 60
Fri Sep 15 09:07:01 2017 : Debug:        probes = 3
Fri Sep 15 09:07:01 2017 : Debug:        interval = 3
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: Registering ldap_groupcmp 
for Ldap-Group
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: Registering ldap_xlat with 
xlat_name ldap
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: reading ldap<->radius 
mappings from file /etc/freeradius/ldap.attrmap
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusCheckItem mapped 
to RADIUS $GENERIC$
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusReplyItem mapped 
to RADIUS $GENERIC$
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusAuthType mapped 
to RADIUS Auth-Type
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusSimultaneousUse 
mapped to RADIUS Simultaneous-Use
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusCalledStationId 
mapped to RADIUS Called-Station-Id
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusCallingStationId 
mapped to RADIUS Calling-Station-Id
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP lmPassword mapped to 
RADIUS LM-Password
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP ntPassword mapped to 
RADIUS NT-Password
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP sambaLmPassword mapped 
to RADIUS LM-Password
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP sambaNtPassword mapped 
to RADIUS NT-Password
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP dBCSPwd mapped to 
RADIUS LM-Password
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP userPassword mapped to 
RADIUS Password-With-Header
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP acctFlags mapped to 
RADIUS SMB-Account-CTRL-TEXT
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusExpiration mapped 
to RADIUS Expiration
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusNASIpAddress 
mapped to RADIUS NAS-IP-Address
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusServiceType 
mapped to RADIUS Service-Type
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedProtocol 
mapped to RADIUS Framed-Protocol
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedIPAddress 
mapped to RADIUS Framed-IP-Address
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask 
mapped to RADIUS Framed-IP-Netmask
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedRoute 
mapped to RADIUS Framed-Route
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedRouting 
mapped to RADIUS Framed-Routing
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFilterId mapped 
to RADIUS Filter-Id
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped 
to RADIUS Framed-MTU
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedCompression 
mapped to RADIUS Framed-Compression
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginIPHost 
mapped to RADIUS Login-IP-Host
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginService 
mapped to RADIUS Login-Service
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginTCPPort 
mapped to RADIUS Login-TCP-Port
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusCallbackNumber 
mapped to RADIUS Callback-Number
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusCallbackId mapped 
to RADIUS Callback-Id
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork 
mapped to RADIUS Framed-IPX-Network
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusClass mapped to 
RADIUS Class
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusSessionTimeout 
mapped to RADIUS Session-Timeout
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusIdleTimeout 
mapped to RADIUS Idle-Timeout
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusTerminationAction 
mapped to RADIUS Termination-Action
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginLATService 
mapped to RADIUS Login-LAT-Service
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginLATNode 
mapped to RADIUS Login-LAT-Node
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginLATGroup 
mapped to RADIUS Login-LAT-Group
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP 
radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusPortLimit mapped 
to RADIUS Port-Limit
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusLoginLATPort 
mapped to RADIUS Login-LAT-Port
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusReplyMessage 
mapped to RADIUS Reply-Message
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusTunnelType mapped 
to RADIUS Tunnel-Type
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP radiusTunnelMediumType 
mapped to RADIUS Tunnel-Medium-Type
Fri Sep 15 09:07:01 2017 : Debug: rlm_ldap: LDAP 
radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id
Fri Sep 15 09:07:01 2017 : Debug: conns: 0x2706520
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_eap, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_eap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "eap" 
from file /etc/freeradius/eap.conf
Fri Sep 15 09:07:01 2017 : Debug:   eap {
Fri Sep 15 09:07:01 2017 : Debug:       default_eap_type = "md5"
Fri Sep 15 09:07:01 2017 : Debug:       timer_expire = 60
Fri Sep 15 09:07:01 2017 : Debug:       ignore_unknown_eap_types = no
Fri Sep 15 09:07:01 2017 : Debug: cisco_accounting_username_bug = no
Fri Sep 15 09:07:01 2017 : Debug:       max_sessions = 1024
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_md5
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-md5
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_leap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-leap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-gtc
Fri Sep 15 09:07:01 2017 : Debug:    gtc {
Fri Sep 15 09:07:01 2017 : Debug:        challenge = "Password: "
Fri Sep 15 09:07:01 2017 : Debug:        auth_type = "PAP"
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_tls
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-tls
Fri Sep 15 09:07:01 2017 : Debug:    tls {
Fri Sep 15 09:07:01 2017 : Debug:        rsa_key_exchange = no
Fri Sep 15 09:07:01 2017 : Debug:        dh_key_exchange = yes
Fri Sep 15 09:07:01 2017 : Debug:        rsa_key_length = 512
Fri Sep 15 09:07:01 2017 : Debug:        dh_key_length = 512
Fri Sep 15 09:07:01 2017 : Debug:        verify_depth = 0
Fri Sep 15 09:07:01 2017 : Debug:        CA_path = "/etc/freeradius/certs"
Fri Sep 15 09:07:01 2017 : Debug:        pem_file_type = yes
Fri Sep 15 09:07:01 2017 : Debug:        private_key_file = 
"/etc/freeradius/certs/server.key"
Fri Sep 15 09:07:01 2017 : Debug:        certificate_file = 
"/etc/freeradius/certs/server.pem"
Fri Sep 15 09:07:01 2017 : Debug:        CA_file = 
"/etc/freeradius/certs/ca.pem"
Fri Sep 15 09:07:01 2017 : Debug:        private_key_password = 
"si7ys4mxs984mxksj4oi"
Fri Sep 15 09:07:01 2017 : Debug:        dh_file = 
"/etc/freeradius/certs/dh"
Fri Sep 15 09:07:01 2017 : Debug:        random_file = "/dev/urandom"
Fri Sep 15 09:07:01 2017 : Debug:        fragment_size = 1024
Fri Sep 15 09:07:01 2017 : Debug:        include_length = yes
Fri Sep 15 09:07:01 2017 : Debug:        check_crl = no
Fri Sep 15 09:07:01 2017 : Debug:        cipher_list = "DEFAULT"
Fri Sep 15 09:07:01 2017 : Debug:        make_cert_command = 
"/etc/freeradius/certs/bootstrap"
Fri Sep 15 09:07:01 2017 : Debug:        ecdh_curve = "prime256v1"
Fri Sep 15 09:07:01 2017 : Debug:     cache {
Fri Sep 15 09:07:01 2017 : Debug:         enable = no
Fri Sep 15 09:07:01 2017 : Debug:         lifetime = 24
Fri Sep 15 09:07:01 2017 : Debug:         max_entries = 255
Fri Sep 15 09:07:01 2017 : Debug:     }
Fri Sep 15 09:07:01 2017 : Debug:     verify {
Fri Sep 15 09:07:01 2017 : Debug:     }
Fri Sep 15 09:07:01 2017 : Debug:     ocsp {
Fri Sep 15 09:07:01 2017 : Debug:         enable = no
Fri Sep 15 09:07:01 2017 : Debug:         override_cert_url = yes
Fri Sep 15 09:07:01 2017 : Debug:         url = "http://127.0.0.1/ocsp/"
Fri Sep 15 09:07:01 2017 : Debug:         use_nonce = yes
Fri Sep 15 09:07:01 2017 : Debug:         timeout = 0
Fri Sep 15 09:07:01 2017 : Debug:         softfail = no
Fri Sep 15 09:07:01 2017 : Debug:     }
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-ttls
Fri Sep 15 09:07:01 2017 : Debug:    ttls {
Fri Sep 15 09:07:01 2017 : Debug:        default_eap_type = "md5"
Fri Sep 15 09:07:01 2017 : Debug:        copy_request_to_tunnel = yes
Fri Sep 15 09:07:01 2017 : Debug:        use_tunneled_reply = yes
Fri Sep 15 09:07:01 2017 : Debug:        virtual_server = "inner-tunnel"
Fri Sep 15 09:07:01 2017 : Debug:        include_length = yes
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module rlm_eap_peap
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-peap
Fri Sep 15 09:07:01 2017 : Debug:    peap {
Fri Sep 15 09:07:01 2017 : Debug:        default_eap_type = "mschapv2"
Fri Sep 15 09:07:01 2017 : Debug:        copy_request_to_tunnel = yes
Fri Sep 15 09:07:01 2017 : Debug:        use_tunneled_reply = yes
Fri Sep 15 09:07:01 2017 : Debug: proxy_tunneled_request_as_eap = yes
Fri Sep 15 09:07:01 2017 : Debug:        virtual_server = "inner-tunnel"
Fri Sep 15 09:07:01 2017 : Debug:        soh = no
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to sub-module 
rlm_eap_mschapv2
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating eap-mschapv2
Fri Sep 15 09:07:01 2017 : Debug:    mschapv2 {
Fri Sep 15 09:07:01 2017 : Debug:        with_ntdomain_hack = no
Fri Sep 15 09:07:01 2017 : Debug:        send_error = no
Fri Sep 15 09:07:01 2017 : Debug:    }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking authorize {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_preprocess, checking 
if it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_preprocess
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"preprocess" from file /etc/freeradius/modules/preprocess
Fri Sep 15 09:07:01 2017 : Debug:   preprocess {
Fri Sep 15 09:07:01 2017 : Debug:       huntgroups = 
"/etc/freeradius/huntgroups"
Fri Sep 15 09:07:01 2017 : Debug:       hints = "/etc/freeradius/hints"
Fri Sep 15 09:07:01 2017 : Debug:       with_ascend_hack = no
Fri Sep 15 09:07:01 2017 : Debug:       ascend_channels_per_line = 23
Fri Sep 15 09:07:01 2017 : Debug:       with_ntdomain_hack = no
Fri Sep 15 09:07:01 2017 : Debug: with_specialix_jetstream_hack = no
Fri Sep 15 09:07:01 2017 : Debug:       with_cisco_vsa_hack = no
Fri Sep 15 09:07:01 2017 : Debug:       with_alvarion_vsa_hack = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/huntgroups
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/hints
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_realm, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_realm
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "suffix" 
from file /etc/freeradius/modules/realm
Fri Sep 15 09:07:01 2017 : Debug:   realm suffix {
Fri Sep 15 09:07:01 2017 : Debug:       format = "suffix"
Fri Sep 15 09:07:01 2017 : Debug:       delimiter = "@"
Fri Sep 15 09:07:01 2017 : Debug:       ignore_default = no
Fri Sep 15 09:07:01 2017 : Debug:       ignore_null = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_files, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_files
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "files" 
from file /etc/freeradius/modules/files
Fri Sep 15 09:07:01 2017 : Debug:   files {
Fri Sep 15 09:07:01 2017 : Debug:       usersfile = "/etc/freeradius/users"
Fri Sep 15 09:07:01 2017 : Debug:       acctusersfile = 
"/etc/freeradius/acct_users"
Fri Sep 15 09:07:01 2017 : Debug:       preproxy_usersfile = 
"/etc/freeradius/preproxy_users"
Fri Sep 15 09:07:01 2017 : Debug:       compat = "no"
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/users
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/acct_users
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/preproxy_users
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking preacct {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_acct_unique, checking 
if it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_acct_unique
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"acct_unique" from file /etc/freeradius/modules/acct_unique
Fri Sep 15 09:07:01 2017 : Debug:   acct_unique {
Fri Sep 15 09:07:01 2017 : Debug:       key = "User-Name, 
Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking accounting {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_detail, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_detail
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "detail" 
from file /etc/freeradius/modules/detail
Fri Sep 15 09:07:01 2017 : Debug:   detail {
Fri Sep 15 09:07:01 2017 : Debug:       detailfile = 
"/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Fri Sep 15 09:07:01 2017 : Debug:       header = "%t"
Fri Sep 15 09:07:01 2017 : Debug:       detailperm = 384
Fri Sep 15 09:07:01 2017 : Debug:       dirperm = 493
Fri Sep 15 09:07:01 2017 : Debug:       locking = no
Fri Sep 15 09:07:01 2017 : Debug:       log_packet_header = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_unix, checking if it's 
valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_unix
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module "unix" 
from file /etc/freeradius/modules/unix
Fri Sep 15 09:07:01 2017 : Debug:   unix {
Fri Sep 15 09:07:01 2017 : Debug:       radwtmp = 
"/var/log/freeradius/radwtmp"
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_attr_filter, checking 
if it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_attr_filter
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"attr_filter.accounting_response" from file 
/etc/freeradius/modules/attr_filter
Fri Sep 15 09:07:01 2017 : Debug:   attr_filter 
attr_filter.accounting_response {
Fri Sep 15 09:07:01 2017 : Debug:       attrsfile = 
"/etc/freeradius/attrs.accounting_response"
Fri Sep 15 09:07:01 2017 : Debug:       key = "%{User-Name}"
Fri Sep 15 09:07:01 2017 : Debug:       relaxed = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/attrs.accounting_response
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking session {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:     (Loaded rlm_radutmp, checking if 
it's valid)
Fri Sep 15 09:07:01 2017 : Debug:  Module: Linked to module rlm_radutmp
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"radutmp" from file /etc/freeradius/modules/radutmp
Fri Sep 15 09:07:01 2017 : Debug:   radutmp {
Fri Sep 15 09:07:01 2017 : Debug:       filename = 
"/var/log/freeradius/radutmp"
Fri Sep 15 09:07:01 2017 : Debug:       username = "%{User-Name}"
Fri Sep 15 09:07:01 2017 : Debug:       case_sensitive = yes
Fri Sep 15 09:07:01 2017 : Debug:       check_with_nas = yes
Fri Sep 15 09:07:01 2017 : Debug:       perm = 384
Fri Sep 15 09:07:01 2017 : Debug:       callerid = yes
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking post-proxy {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking post-auth {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Instantiating module 
"attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Fri Sep 15 09:07:01 2017 : Debug:   attr_filter attr_filter.access_reject {
Fri Sep 15 09:07:01 2017 : Debug:       attrsfile = 
"/etc/freeradius/attrs.access_reject"
Fri Sep 15 09:07:01 2017 : Debug:       key = "%{User-Name}"
Fri Sep 15 09:07:01 2017 : Debug:       relaxed = no
Fri Sep 15 09:07:01 2017 : Debug:   }
Fri Sep 15 09:07:01 2017 : Debug: reading pairlist file 
/etc/freeradius/attrs.access_reject
Fri Sep 15 09:07:01 2017 : Debug:  } # modules
Fri Sep 15 09:07:01 2017 : Debug: } # server
Fri Sep 15 09:07:01 2017 : Debug: server inner-tunnel { # from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:01 2017 : Debug:  modules {
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking authenticate {...} 
for more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking authorize {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking session {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking post-proxy {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  Module: Checking post-auth {...} for 
more modules to load
Fri Sep 15 09:07:01 2017 : Debug:  } # modules
Fri Sep 15 09:07:01 2017 : Debug: } # server
Fri Sep 15 09:07:01 2017 : Debug: radiusd: #### Opening IP addresses and 
Ports ####
Fri Sep 15 09:07:01 2017 : Debug: listen {
Fri Sep 15 09:07:01 2017 : Debug:      type = "auth"
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = *
Fri Sep 15 09:07:01 2017 : Debug:      port = 0
Fri Sep 15 09:07:01 2017 : Debug: }
Fri Sep 15 09:07:01 2017 : Debug: listen {
Fri Sep 15 09:07:01 2017 : Debug:      type = "acct"
Fri Sep 15 09:07:01 2017 : Debug:      ipaddr = *
Fri Sep 15 09:07:01 2017 : Debug:      port = 0
Fri Sep 15 09:07:01 2017 : Debug: }
Fri Sep 15 09:07:01 2017 : Debug: listen {
Fri Sep 15 09:07:01 2017 : Debug:       type = "auth"
Fri Sep 15 09:07:01 2017 : Debug:       ipaddr = 127.0.0.1
Fri Sep 15 09:07:01 2017 : Debug:       port = 18120
Fri Sep 15 09:07:01 2017 : Debug: }
Fri Sep 15 09:07:01 2017 : Debug:  ... adding new socket proxy address * 
port 51874
Fri Sep 15 09:07:01 2017 : Debug:  ... adding new socket proxy address * 
port 60324
Fri Sep 15 09:07:01 2017 : Debug:  ... adding new socket proxy address * 
port 57887
Fri Sep 15 09:07:01 2017 : Debug: Listening on authentication address * 
port 1812
Fri Sep 15 09:07:01 2017 : Debug: Listening on accounting address * port 
1813
Fri Sep 15 09:07:01 2017 : Debug: Listening on authentication address 
127.0.0.1 port 18120 as server inner-tunnel
Fri Sep 15 09:07:01 2017 : Debug: Listening on proxy address * port 1814
Fri Sep 15 09:07:01 2017 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=30, length=287
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 0x02020017017073697461727a40696a702e70616e2e706c
     Message-Authenticator = 0xe3b9300c51ffe43e482510eccd899c44
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 2 
length 23
Fri Sep 15 09:07:16 2017 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = updated
Fri Sep 15 09:07:16 2017 : Info: [files] users: Matched entry DEFAULT at 
line 12
Fri Sep 15 09:07:16 2017 : Info: ++[files] = ok
Fri Sep 15 09:07:16 2017 : Info: [ldap] performing user authorization 
for psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
%{Stripped-User-Name} -> psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
dc=ijp,dc=pan,dc=local -> dc=ijp,dc=pan,dc=local
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] attempting LDAP reconnection
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] (re)connect to 
ldap1.mydomain.com:389, authentication 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] bind as 
cn=freeradius,ou=services,dc=ijp,dc=pan,dc=local/rad--IJP--02 to 
ldap1.mydomain.com:389
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] waiting for bind result ...
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] Bind was successful
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] performing search in 
dc=ijp,dc=pan,dc=local, with filter (sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] rebind to URL 
ldap://mydomain.com/CN=Configuration,DC=ijp,DC=pan,DC=local
Fri Sep 15 09:07:16 2017 : Info: [ldap] No default NMAS login sequence
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for check items in 
directory...
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for reply items in 
directory...
Fri Sep 15 09:07:16 2017 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Fri Sep 15 09:07:16 2017 : Info: ++[ldap] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[expiration] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[logintime] = noop
Fri Sep 15 09:07:16 2017 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Fri Sep 15 09:07:16 2017 : Info: ++[pap] = noop
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = updated
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP Identity
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type md5
Fri Sep 15 09:07:16 2017 : Debug: rlm_eap_md5: Issuing Challenge
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 30 to 10.24.100.41 port 32773
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 := "200"
     Reply-Message = "YYYY HIT: my_wifi"
     EAP-Message = 0x01030016041093d2cac6b3d1336be38f63896a404f69
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebcc2d4be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 0.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=31, length=288
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 0x020300060319
     State = 0xbcc1d00ebcc2d4be84f2b34ad01933f1
     Message-Authenticator = 0xa15f469880c1d97b82fba834c87bd10b
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 3 
length 6
Fri Sep 15 09:07:16 2017 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = updated
Fri Sep 15 09:07:16 2017 : Info: [files] users: Matched entry DEFAULT at 
line 12
Fri Sep 15 09:07:16 2017 : Info: ++[files] = ok
Fri Sep 15 09:07:16 2017 : Info: [ldap] performing user authorization 
for psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
%{Stripped-User-Name} -> psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
dc=ijp,dc=pan,dc=local -> dc=ijp,dc=pan,dc=local
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] performing search in 
dc=ijp,dc=pan,dc=local, with filter (sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] rebind to URL 
ldap://mydomain.com/CN=Configuration,DC=ijp,DC=pan,DC=local
Fri Sep 15 09:07:16 2017 : Info: [ldap] No default NMAS login sequence
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for check items in 
directory...
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for reply items in 
directory...
Fri Sep 15 09:07:16 2017 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Fri Sep 15 09:07:16 2017 : Info: ++[ldap] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[expiration] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[logintime] = noop
Fri Sep 15 09:07:16 2017 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Fri Sep 15 09:07:16 2017 : Info: ++[pap] = noop
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = updated
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP NAK
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type tls
Fri Sep 15 09:07:16 2017 : Info: [tls] Initiate
Fri Sep 15 09:07:16 2017 : Info: [tls] Start returned 1
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 31 to 10.24.100.41 port 32773
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 := "200"
     Reply-Message = "YYYY HIT: my_wifi"
     EAP-Message = 0x010400061920
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebdc5c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 1.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=32, length=395
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 
0x0204007119800000006716030100620100005e030159bb7c3b7f85ba3410a1b66afdd8eb687b96f62ad26175641d3ed2aa9cee899300001cc014c013003900330035002fc00ac00900380032000a00130005000401000019000a0006000400170018000b0002010000170000ff01000100
     State = 0xbcc1d00ebdc5c9be84f2b34ad01933f1
     Message-Authenticator = 0xdb5b1081947941e25dbe17961232739c
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 4 
length 113
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Debug:   TLS Length 103
Fri Sep 15 09:07:16 2017 : Info: [peap] Length Included
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 11
Fri Sep 15 09:07:16 2017 : Info: [peap]     (other): before/accept 
initialization
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: before/accept 
initialization
Fri Sep 15 09:07:16 2017 : Info: [peap] <<< TLS 1.0 Handshake [length 
0062], ClientHello
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 Handshake [length 
0039], ServerHello
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 Handshake [length 
08a6], Certificate
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 Handshake [length 
014b], ServerKeyExchange
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 Handshake [length 
0004], ServerHelloDone
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: Need to read 
more data: unknown state
Fri Sep 15 09:07:16 2017 : Debug: In SSL Handshake Phase
Fri Sep 15 09:07:16 2017 : Debug: In SSL Accept mode
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 13
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_HANDLED
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 32 to 10.24.100.41 port 32773
     EAP-Message = 
0x0105040019c000000a4216030100390200003503018185835081a6c1001c29d0732978cd92ae81954b6b08f4e4f5c76d011aebb7b400c01400000dff01000100000b00040300010216030108a60b0008a200089f000488308204843082036ca003020102020100300d06092a864886f70d0101050500308188310b300906035504061302504c3114301206035504080c0b4d616c6f706f6c736b6965310f300d06035504070c064b72616b6f7731263024060355040a0c1d496e737479747574204a657a796b6120506f6c736b6965676f2050414e310b3009060355040b0c024954311d301b06035504030c147375626361312e696a702e70616e2e6c
     EAP-Message = 
0x6f63616c301e170d3137303832313131303233355a170d3332303831373131303233355a308187310b300906035504061302504c3114301206035504080c0b4d616c6f706f6c736b6965310f300d06035504070c064b72616b6f7731263024060355040a0c1d496e737479747574204a657a796b6120506f6c736b6965676f2050414e310b3009060355040b0c024954311c301a06035504030c136c646170312e696a702e70616e2e6c6f63616c30820122300d06092a864886f70d01010105000382010f003082010a0282010100bf2015679983021d7e971d84ea7c7f5ba06e4b4808b7674f687fc0880cf4635a2db718cb22982ddd8822afe970ec
     EAP-Message = 
0x2d745deac6e6acf21e7330b77cd86fdb28ab4e04eda8789771a6e30890e6b67c3e111bcd017b12856072c19afefc1d07fcd1a6c53e66cdd8008e8766a1e7dbce66966e07814e08c6bbc2399cae3694dba14c021b588a967cbf5e23197c8593cf28bd84f44a03ecfdfc4e34000e07e9edf676b57633787cb5c3a7b4406c8f4d535c2ffe08f5ce60756500f3887c62b1c34c1088b27de433a9aef286b914e38f6bb307d322586bb33dcd74352dfc37e28eae33f4299d5d120a521a6c691a0980a22ad63ed220331210383ee14edd24be3088b90203010001a381f73081f430090603551d1304023000302c06096086480186f842010d041f161d4f70656e
     EAP-Message = 
0x53534c2047656e657261746564204365727469666963617465301d0603551d0e041604143b1a3710cdf72a3288cc76cc3d5ad3e9b2384503301f0603551d23041830168014c1d62dd5cd9967b990856c18acc7f2e64f40a29c304106082b0601050507010104353033303106082b060105050730028625687474703a2f2f6b302e696a702e70616e2e6c6f63616c2f63612f7375626361312e63727430360603551d1f042f302d302ba029a0278625687474703a2f2f6b312e696a702e70616e2e6c6f63616c2f63612f7375626361312e63726c300d06092a864886f70d0101050500038201010062dae87f130c1ab3ef0acf5bd31aed2b4f524b4a84
     EAP-Message = 0xaf5192d4e9d1c6301ce43d01
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebec4c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 2.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=33, length=288
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 0x020500061900
     State = 0xbcc1d00ebec4c9be84f2b34ad01933f1
     Message-Authenticator = 0xfb763038263f85526f7d8abaa936a1bf
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 5 
length 6
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] Received TLS ACK
Fri Sep 15 09:07:16 2017 : Info: [peap] ACK handshake fragment handler
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 1
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 13
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_HANDLED
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 33 to 10.24.100.41 port 32773
     EAP-Message = 
0x010603fc1940b01e45053cb5d289d8a07c691f42babbaf4150ea36d712beb08a0c1eaa301b5df2b9d6975f9dfecbe42c847567bd961d58a520d68fb34854326b7dba525597e4ac0b1a5a66b9d677be1f5e0adfd325311af927356634a7f8aee2770898b4044daf46d89745f7262026f2e1b81caa53a4aebd5310ba988cd6364fd6b79795f38e23d047ad0af23bbcd5407317cb01b49b61eac8d67cf784948797aba3968b094cdfb93c2177da70b000f1797bf3bd979b8317daec32cd87cfa3a471d891abdacea5776581fb2416c93b2f01ba6b6728099d7e26d7974eec099035ee212077e70004113082040d308202f5a003020102020900fda7ea2091
     EAP-Message = 
0x83fda3300d06092a864886f70d01010505003077310b300906035504061302504c3114301206035504080c0b4d616c6f706f6c736b696531263024060355040a0c1d496e737479747574204a657a796b6120506f6c736b6965676f2050414e310b3009060355040b0c024954311d301b06035504030c14726f6f7463612e696a702e70616e2e6c6f63616c301e170d3137303832313130343434315a170d3337303831363130343434315a308188310b300906035504061302504c3114301206035504080c0b4d616c6f706f6c736b6965310f300d06035504070c064b72616b6f7731263024060355040a0c1d496e737479747574204a657a796b6120
     EAP-Message = 
0x506f6c736b6965676f2050414e310b3009060355040b0c024954311d301b06035504030c147375626361312e696a702e70616e2e6c6f63616c30820122300d06092a864886f70d01010105000382010f003082010a0282010100cec338083565b45728e1f8176ba4daabda4ea88555201f503e3977492e85b49759cd232e7934acd16194ca3889d6975a29f68017427738b2fe57db0951e879afb9f5eae6a75a8d8b96cc12acb9686227322a555ec7e298b77b139874e9c0935d52117991a27281644f351bbacf3f804a1da86f26e784a507ec21e3aacfaf5e686fc01e570397f2dcc5822edd7c0b59f20dc48c408453ba7e9ea170a72c175ca352818c
     EAP-Message = 
0xf095d192d42cf58272c00c477f2e1755104ced45567186bd44f7b3ab6c947a427e0f3e54c5d88e544c349f16737de5c8191785c2a5af1be735466dff6bdb08682494b1b54c25429014c59437925c441f4c1e42ceb12b7d060b7159f5350203010001a38189308186301d0603551d0e04160414c1d62dd5cd9967b990856c18acc7f2e64f40a29c301f0603551d230418301680148ae199d104b425c1279d439e0b0d2487dfda236c300c0603551d13040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f6b312e696a702e70616e2e6c6f63616c2f63612f726f6f7463612e63726c300d06092a864886f70d0101050500
     EAP-Message = 0x0382010100a7ba01
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebfc7c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 3.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=34, length=288
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 0x020600061900
     State = 0xbcc1d00ebfc7c9be84f2b34ad01933f1
     Message-Authenticator = 0x78af48b2e32899574eb459692278e13a
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 6 
length 6
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] Received TLS ACK
Fri Sep 15 09:07:16 2017 : Info: [peap] ACK handshake fragment handler
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 1
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 13
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_HANDLED
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 34 to 10.24.100.41 port 32773
     EAP-Message = 
0x0107025c19004d16d1c7a4c127b06c3974533a055af202e7fe05f13dc5f78bf50eb852b25913965c85f981b45b174003af43ddbb5d8754406a26645dd06a9d4ce4b1622de1b4cec8a3d91f973b6332ba5fd78ff18e6feb1b87e664ee981c68523c4d9517a9c8f97abbefd1d76ba66dbeee1fe4e8d4420f6606ff280119897d3026e466910f5ebb892ce764e60fc8d7e4eb2f1609348a405b6e92133d1f4a6f612f4a6eee9c1c04677bcf3e574dc88d64e8972be7d01a080968f189d9258bca3419feff11a7409ae6471a32eab899837f79f8c8116f27ecf63daf802cd7b0df1b3a767d46bb4a40f07b0ead84f31ba36292b6df736e38d9b2f25e2e1483
     EAP-Message = 
0x6e854d35643c160301014b0c0001470300174104c749e5af44a1f2c9b879f1f7d840237935fd1df922ab61437f05c1d22a4638aff08e10339671937adc00893635bd845462fc0154817d3b5a116d142e1bac5f4201001bbdf61538895d0d92597c97b5d1ee8399d775cccb53cb7d67b3794daf6a2b452b4e6050d41d9a7411b7457c7294b2e1d736c4ab51ffd5208739525e84115b183aad5ba3e02874c3156f2f6167996e546d7f0e18cec93d124251d483a82cada947992d2c9c8f961939b12d388095aa01a11f88be2dc8517174d7dcc89b1119c5f66512194b940e795c6f119440bfcfdaeceda9855551af8932e73270689e74e474adfd1d07157e
     EAP-Message = 
0x0ee4449c6e6b535f410007efc4607971c3efa594861aa9ee3561f2ad2bc786e7709f9b5e094d809c2561d9d78eecba382efdac6303efd502c1f3b56822599f13b73c72693373256bc1d266769a2ed2201947a1444b2424e3b216030100040e000000
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00eb8c6c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 4.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=35, length=426
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 
0x0207009019800000008616030100461000004241049d9710b7a426a3513d57e030bab3b25a4edf8ca94bbb7eee10006e28e28e5c512206aed775a97bec0a76df64f1fc669507917cabfe556cde04b31ca9f6ac756e1403010001011603010030bda12143c44ac47dd3649040750bb5bb2087fa7dc17179928504e7e470dd78ddfd264d269d3f2fd70711f63f11e67949
     State = 0xbcc1d00eb8c6c9be84f2b34ad01933f1
     Message-Authenticator = 0x06d4628d7d8179d2d01a8385b86bcfd0
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 7 
length 144
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Debug:   TLS Length 134
Fri Sep 15 09:07:16 2017 : Info: [peap] Length Included
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 11
Fri Sep 15 09:07:16 2017 : Info: [peap] <<< TLS 1.0 Handshake [length 
0046], ClientKeyExchange
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec 
[length 0001]
Fri Sep 15 09:07:16 2017 : Info: [peap] <<< TLS 1.0 Handshake [length 
0010], Finished
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec 
[length 0001]
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap] >>> TLS 1.0 Handshake [length 
0010], Finished
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap]     TLS_accept: unknown state
Fri Sep 15 09:07:16 2017 : Info: [peap]     (other): SSL negotiation 
finished successfully
Fri Sep 15 09:07:16 2017 : Debug: SSL Connection Established
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 13
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_HANDLED
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 35 to 10.24.100.41 port 32773
     EAP-Message = 
0x01080041190014030100010116030100309cd4d10a07b4d67d561d06430c7165c09277f7946aa722b96cf27f896ea980206825dc614435f7bf0835e8e484977d23
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00eb9c9c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 5.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=36, length=288
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 0x020800061900
     State = 0xbcc1d00eb9c9c9be84f2b34ad01933f1
     Message-Authenticator = 0x262dea598010395c76016ea6f7099a1f
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 8 
length 6
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] Received TLS ACK
Fri Sep 15 09:07:16 2017 : Info: [peap] ACK handshake is finished
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 3
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 3
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_SUCCESS
Fri Sep 15 09:07:16 2017 : Info: [peap] Session established. Decoding 
tunneled attributes.
Fri Sep 15 09:07:16 2017 : Info: [peap] Peap state TUNNEL ESTABLISHED
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 36 to 10.24.100.41 port 32773
     EAP-Message = 
0x0109002b19001703010020364933ca1f707384c392a6841c48ed1c0e1a241b99f5e087dc818743cb2507d4
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebac8c9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 6.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=37, length=341
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 
0x0209003b1900170301003064732805af4010f3b1137dfc4a31da6d74eb906b3a7c681a01e0f7c9a0fd015df5ebb14b96b6a7c44354cc2260b91b2a
     State = 0xbcc1d00ebac8c9be84f2b34ad01933f1
     Message-Authenticator = 0x329df1765f0c2fc1e6a35faab42c2056
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 9 
length 59
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] Done initial handshake
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_OK
Fri Sep 15 09:07:16 2017 : Info: [peap] Session established. Decoding 
tunneled attributes.
Fri Sep 15 09:07:16 2017 : Info: [peap] Peap state WAITING FOR INNER 
IDENTITY
Fri Sep 15 09:07:16 2017 : Info: [peap] Identity - psitarz@mydomain.com
Fri Sep 15 09:07:16 2017 : Info: [peap] Got inner identity 
'psitarz@mydomain.com'
Fri Sep 15 09:07:16 2017 : Info: [peap] Setting default EAP type for 
tunneled EAP session.
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled request
     EAP-Message = 0x02090017017073697461727a40696a702e70616e2e706c
server  {
Fri Sep 15 09:07:16 2017 : Info: [peap] Setting User-Name to 
psitarz@mydomain.com
Sending tunneled request
     EAP-Message = 0x02090017017073697461727a40696a702e70616e2e706c
     FreeRADIUS-Proxied-To = 127.0.0.1
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
server inner-tunnel {
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 9 
length 23
Fri Sep 15 09:07:16 2017 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = updated
Fri Sep 15 09:07:16 2017 : Info: [files] users: Matched entry DEFAULT at 
line 12
Fri Sep 15 09:07:16 2017 : Info: ++[files] = ok
Fri Sep 15 09:07:16 2017 : Info: [ldap] performing user authorization 
for psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
%{Stripped-User-Name} -> psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
dc=ijp,dc=pan,dc=local -> dc=ijp,dc=pan,dc=local
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] performing search in 
dc=ijp,dc=pan,dc=local, with filter (sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] rebind to URL 
ldap://mydomain.com/CN=Configuration,DC=ijp,DC=pan,DC=local
Fri Sep 15 09:07:16 2017 : Info: [ldap] No default NMAS login sequence
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for check items in 
directory...
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for reply items in 
directory...
Fri Sep 15 09:07:16 2017 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Fri Sep 15 09:07:16 2017 : Info: ++[ldap] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[expiration] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[logintime] = noop
Fri Sep 15 09:07:16 2017 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Fri Sep 15 09:07:16 2017 : Info: ++[pap] = noop
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = updated
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP Identity
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type mschapv2
Fri Sep 15 09:07:16 2017 : Debug: rlm_eap_mschapv2: Issuing Challenge
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
} # server inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled reply code 11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 := "200"
     Reply-Message = "YYYY HIT: my_wifi"
     EAP-Message = 
0x010a002c1a010a0027105c28e3c5119990bfecac594ca8283abe7073697461727a40696a702e70616e2e706c
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xd9fc6e1ed9f6747899ae3f4494b5bd42
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled reply RADIUS code 11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 := "200"
     Reply-Message = "YYYY HIT: my_wifi"
     EAP-Message = 
0x010a002c1a010a0027105c28e3c5119990bfecac594ca8283abe7073697461727a40696a702e70616e2e706c
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xd9fc6e1ed9f6747899ae3f4494b5bd42
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled Access-Challenge
   PEAP tunnel data out 0000: 1a 01 0a 00 27 10 5c 28 e3 c5 11 99 90 bf 
ec ac
   PEAP tunnel data out 0010: 59 4c a8 28 3a be 70 73 69 74 61 72 7a 40 
69 6a
   PEAP tunnel data out 0020: 70 2e 70 61 6e 2e 70 6c
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 37 to 10.24.100.41 port 32773
     EAP-Message = 
0x010a004b190017030100400aa668edae7f810d1ee048d420a7e0da4ed981b1f3600eaf99fcc21365740c8f52c6f995b1dda5c3672245d5189d2e57e02017247a53c2e6bae6c1ba226a5676
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00ebbcbc9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 7.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=38, length=389
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 
0x020a006b190017030100609c8e8afad49636b8659624cca08c0af13596288fa47edf937944bdef3d4e0de58e67e9c03e69aa6231ce684940848f416242f7c72b34a5487f1638a87920db4293467e7e0566b999463ba56d78483646a844ed67b203597983e21fe4d551473f
     State = 0xbcc1d00ebbcbc9be84f2b34ad01933f1
     Message-Authenticator = 0x2f84e9005e5ce14f6b0b4d26cabe49c5
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 10 
length 107
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] Done initial handshake
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_OK
Fri Sep 15 09:07:16 2017 : Info: [peap] Session established. Decoding 
tunneled attributes.
Fri Sep 15 09:07:16 2017 : Info: [peap] Peap state phase2
Fri Sep 15 09:07:16 2017 : Info: [peap] EAP type mschapv2
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled request
     EAP-Message = 
0x020a004d1a020a00483127a0255afce7ebd675f5e2580c500e5e0000000000000000dbdff2050731af4d5e7f6bbcc15f6ba740b157f5df29b787007073697461727a40696a702e70616e2e706c
server  {
Fri Sep 15 09:07:16 2017 : Info: [peap] Setting User-Name to 
psitarz@mydomain.com
Sending tunneled request
     EAP-Message = 
0x020a004d1a020a00483127a0255afce7ebd675f5e2580c500e5e0000000000000000dbdff2050731af4d5e7f6bbcc15f6ba740b157f5df29b787007073697461727a40696a702e70616e2e706c
     FreeRADIUS-Proxied-To = 127.0.0.1
     User-Name = "psitarz@mydomain.com"
     State = 0xd9fc6e1ed9f6747899ae3f4494b5bd42
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
server inner-tunnel {
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 10 
length 77
Fri Sep 15 09:07:16 2017 : Info: [eap] No EAP Start, assuming it's an 
on-going EAP conversation
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = updated
Fri Sep 15 09:07:16 2017 : Info: [files] users: Matched entry DEFAULT at 
line 12
Fri Sep 15 09:07:16 2017 : Info: ++[files] = ok
Fri Sep 15 09:07:16 2017 : Info: [ldap] performing user authorization 
for psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
%{Stripped-User-Name} -> psitarz
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Info: [ldap]     expand: 
dc=ijp,dc=pan,dc=local -> dc=ijp,dc=pan,dc=local
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Checking Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_get_conn: Got Id: 0
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] performing search in 
dc=ijp,dc=pan,dc=local, with filter (sAMAccountName=psitarz)
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] rebind to URL 
ldap://mydomain.com/CN=Configuration,DC=ijp,DC=pan,DC=local
Fri Sep 15 09:07:16 2017 : Info: [ldap] No default NMAS login sequence
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for check items in 
directory...
Fri Sep 15 09:07:16 2017 : Info: [ldap] looking for reply items in 
directory...
Fri Sep 15 09:07:16 2017 : Debug: WARNING: No "known good" password was 
found in LDAP.  Are you sure that the user is configured correctly?
Fri Sep 15 09:07:16 2017 : Debug:   [ldap] ldap_release_conn: Release Id: 0
Fri Sep 15 09:07:16 2017 : Info: ++[ldap] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[expiration] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[logintime] = noop
Fri Sep 15 09:07:16 2017 : Info: [pap] WARNING! No "known good" password 
found for the user.  Authentication may fail because of this.
Fri Sep 15 09:07:16 2017 : Info: ++[pap] = noop
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = updated
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/mschapv2
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type mschapv2
Fri Sep 15 09:07:16 2017 : Info: [mschapv2] # Executing group from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: [mschapv2] +group MS-CHAP {
Fri Sep 15 09:07:16 2017 : Info: [mschap] Creating challenge hash with 
username: psitarz@mydomain.com
Fri Sep 15 09:07:16 2017 : Info: [mschap] Client is using MS-CHAPv2 for 
psitarz@mydomain.com, we need NT-Password
Fri Sep 15 09:07:16 2017 : Info: [mschap] WARNING: Deprecated 
conditional expansion ":-".  See "man unlang" for details
Fri Sep 15 09:07:16 2017 : Info: [mschap]     expand: 
--username=%{Stripped-User-Name:-%{User-Name:-None}} -> --username=psitarz
Fri Sep 15 09:07:16 2017 : Info: [mschap] Creating challenge hash with 
username: psitarz@mydomain.com
Fri Sep 15 09:07:16 2017 : Info: [mschap]     expand: 
--challenge=%{mschap:Challenge:-00} -> --challenge=30cedb6750524fca
Fri Sep 15 09:07:16 2017 : Info: [mschap]     expand: 
--nt-response=%{mschap:NT-Response:-00} -> 
--nt-response=dbdff2050731af4d5e7f6bbcc15f6ba740b157f5df29b787
Fri Sep 15 09:07:16 2017 : Debug: Exec output: Logon failure (0xc000006d)
Fri Sep 15 09:07:16 2017 : Debug: Exec plaintext: Logon failure 
(0xc000006d)
Fri Sep 15 09:07:16 2017 : Info: [mschap] Exec: program returned: 1
Fri Sep 15 09:07:16 2017 : Info: [mschap] External script failed.
Fri Sep 15 09:07:16 2017 : Info: [mschap] FAILED: MS-CHAP2-Response is 
incorrect
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = reject
Fri Sep 15 09:07:16 2017 : Info: +} # group MS-CHAP = reject
Fri Sep 15 09:07:16 2017 : Info: [eap] Freeing handler
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = reject
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = reject
Fri Sep 15 09:07:16 2017 : Info: Failed to authenticate the user.
Fri Sep 15 09:07:16 2017 : Info: Using Post-Auth-Type REJECT
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: +group REJECT {
Fri Sep 15 09:07:16 2017 : Info: [attr_filter.access_reject] expand: 
%{User-Name} -> psitarz@mydomain.com
Fri Sep 15 09:07:16 2017 : Debug: attr_filter: Matched entry DEFAULT at 
line 11
Fri Sep 15 09:07:16 2017 : Info: ++[attr_filter.access_reject] = updated
Fri Sep 15 09:07:16 2017 : Info: +} # group REJECT = updated
} # server inner-tunnel
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled reply code 3
     Reply-Message = "YYYY HIT: my_wifi"
     MS-CHAP-Error = "\nE=691 R=1"
     EAP-Message = 0x040a0004
     Message-Authenticator = 0x00000000000000000000000000000000
Fri Sep 15 09:07:16 2017 : Info: [peap] Got tunneled reply RADIUS code 3
     Reply-Message = "YYYY HIT: my_wifi"
     MS-CHAP-Error = "\nE=691 R=1"
     EAP-Message = 0x040a0004
     Message-Authenticator = 0x00000000000000000000000000000000
Fri Sep 15 09:07:16 2017 : Info: [peap] Tunneled authentication was 
rejected.
Fri Sep 15 09:07:16 2017 : Info: [peap] FAILURE
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = handled
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 38 to 10.24.100.41 port 32773
     EAP-Message = 
0x010b002b1900170301002081117f973bff6879014450c7523c384a68e5d5c65e7d952d690f53d929d388a5
     Message-Authenticator = 0x00000000000000000000000000000000
     State = 0xbcc1d00eb4cac9be84f2b34ad01933f1
Fri Sep 15 09:07:16 2017 : Info: Finished request 8.
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.24.100.41 port 32773, 
id=39, length=325
     User-Name = "psitarz@mydomain.com"
     Chargeable-User-Identity = ""
     Location-Capable = Civix-Location
     Calling-Station-Id = "08-ed-b9-92-1e-85"
     Called-Station-Id = "7c-0e-ce-ea-b7-20:my_wifi"
     NAS-Port = 13
     Cisco-AVPair = "audit-session-id=0a18642900002ba859bb7b8b"
     Acct-Session-Id = "59bb7b8b/08:ed:b9:92:1e:85/506"
     NAS-IP-Address = 10.24.100.41
     NAS-Identifier = "my_wifi"
     Airespace-Wlan-Id = 3
     Service-Type = Framed-User
     Framed-MTU = 1300
     NAS-Port-Type = Wireless-802.11
     Tunnel-Type:0 = VLAN
     Tunnel-Medium-Type:0 = IEEE-802
     Tunnel-Private-Group-Id:0 = "216"
     EAP-Message = 
0x020b002b1900170301002018e0dac5f02e034e89760f78d0c904adb33c3619b1c5a0a946f01f7f0beed16d
     State = 0xbcc1d00eb4cac9be84f2b34ad01933f1
     Message-Authenticator = 0x867f83b390796be84d7ea49fa63c6775
Fri Sep 15 09:07:16 2017 : Info: # Executing section authorize from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authorize {
Fri Sep 15 09:07:16 2017 : Info: ++[preprocess] = ok
Fri Sep 15 09:07:16 2017 : Info: ++[chap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[mschap] = noop
Fri Sep 15 09:07:16 2017 : Info: ++[digest] = noop
Fri Sep 15 09:07:16 2017 : Info: [suffix] Looking up realm 
"mydomain.com" for User-Name = "psitarz@mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Found realm "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Stripped-User-Name = 
"psitarz"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Adding Realm = "mydomain.com"
Fri Sep 15 09:07:16 2017 : Info: [suffix] Authentication realm is LOCAL.
Fri Sep 15 09:07:16 2017 : Info: ++[suffix] = ok
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP packet type response id 11 
length 43
Fri Sep 15 09:07:16 2017 : Info: [eap] Continuing tunnel setup.
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = ok
Fri Sep 15 09:07:16 2017 : Info: +} # group authorize = ok
Fri Sep 15 09:07:16 2017 : Info: Found Auth-Type = EAP
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group authenticate {
Fri Sep 15 09:07:16 2017 : Info: [eap] Request found, released from the list
Fri Sep 15 09:07:16 2017 : Info: [eap] EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] processing type peap
Fri Sep 15 09:07:16 2017 : Info: [peap] processing EAP-TLS
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_verify returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] Done initial handshake
Fri Sep 15 09:07:16 2017 : Info: [peap] eaptls_process returned 7
Fri Sep 15 09:07:16 2017 : Info: [peap] EAPTLS_OK
Fri Sep 15 09:07:16 2017 : Info: [peap] Session established. Decoding 
tunneled attributes.
Fri Sep 15 09:07:16 2017 : Info: [peap] Peap state send tlv failure
Fri Sep 15 09:07:16 2017 : Info: [peap] Received EAP-TLV response.
Fri Sep 15 09:07:16 2017 : Info: [peap]  The users session was 
previously rejected: returning reject (again.)
Fri Sep 15 09:07:16 2017 : Info: [peap]  *** This means you need to read 
the PREVIOUS messages in the debug output
Fri Sep 15 09:07:16 2017 : Info: [peap]  *** to find out the reason why 
the user was rejected.
Fri Sep 15 09:07:16 2017 : Info: [peap]  *** Look for "reject" or 
"fail".  Those earlier messages will tell you.
Fri Sep 15 09:07:16 2017 : Info: [peap]  *** what went wrong, and how to 
fix the problem.
Fri Sep 15 09:07:16 2017 : Info: [eap] Handler failed in EAP/peap
Fri Sep 15 09:07:16 2017 : Info: [eap] Failed in EAP select
Fri Sep 15 09:07:16 2017 : Info: ++[eap] = invalid
Fri Sep 15 09:07:16 2017 : Info: +} # group authenticate = invalid
Fri Sep 15 09:07:16 2017 : Info: Failed to authenticate the user.
Fri Sep 15 09:07:16 2017 : Info: Using Post-Auth-Type REJECT
Fri Sep 15 09:07:16 2017 : Info: # Executing group from file 
/etc/freeradius/sites-enabled/default
Fri Sep 15 09:07:16 2017 : Info: +group REJECT {
Fri Sep 15 09:07:16 2017 : Info: [attr_filter.access_reject] expand: 
%{User-Name} -> psitarz@mydomain.com
Fri Sep 15 09:07:16 2017 : Debug: attr_filter: Matched entry DEFAULT at 
line 11
Fri Sep 15 09:07:16 2017 : Info: ++[attr_filter.access_reject] = updated
Fri Sep 15 09:07:16 2017 : Info: +} # group REJECT = updated
Fri Sep 15 09:07:16 2017 : Info: Delaying reject of request 9 for 1 seconds
Fri Sep 15 09:07:16 2017 : Debug: Going to the next request
Fri Sep 15 09:07:16 2017 : Debug: Waking up in 0.9 seconds.
Fri Sep 15 09:07:17 2017 : Info: Sending delayed reject for request 9
Sending Access-Reject of id 39 to 10.24.100.41 port 32773
     EAP-Message = 0x040b0004
     Message-Authenticator = 0x00000000000000000000000000000000
Fri Sep 15 09:07:17 2017 : Debug: Waking up in 3.8 seconds.


-- 
Z poważaniem / Yours sincerely
Zenon Matuszyk
mobile: 00 48 797 004 938
e-mail: zenon.matuszyk@networkers.pl
www: http://www.networkers.pl