Re: passwd and unlang

10 Feb 2017

      OK, upgraded to 3.0.12
Fri Feb 10 14:26:17 2017 : Debug:   freeradius-server        : 3.0.12

Now it looks like this:

Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (1)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (1)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (1)     } # if (Called-Station-ID =~
/:test$/)  = updated

Full startup and access request:

[root@radrad mods-available]# sudo /usr/local/freeradius/sbin/radiusd -XXX
Fri Feb 10 14:29:19 2017 : Debug: Server was built with:
Fri Feb 10 14:29:19 2017 : Debug:   accounting               : yes
Fri Feb 10 14:29:19 2017 : Debug:   authentication           : yes
Fri Feb 10 14:29:19 2017 : Debug:   ascend-binary-attributes : yes
Fri Feb 10 14:29:19 2017 : Debug:   coa                      : yes
Fri Feb 10 14:29:19 2017 : Debug:   control-socket           : yes
Fri Feb 10 14:29:19 2017 : Debug:   detail                   : yes
Fri Feb 10 14:29:19 2017 : Debug:   dhcp                     : yes
Fri Feb 10 14:29:19 2017 : Debug:   dynamic-clients          : yes
Fri Feb 10 14:29:19 2017 : Debug:   osfc2                    : no
Fri Feb 10 14:29:19 2017 : Debug:   proxy                    : yes
Fri Feb 10 14:29:19 2017 : Debug:   regex-pcre               : no
Fri Feb 10 14:29:19 2017 : Debug:   regex-posix              : yes
Fri Feb 10 14:29:19 2017 : Debug:   regex-posix-extended     : yes
Fri Feb 10 14:29:19 2017 : Debug:   session-management       : yes
Fri Feb 10 14:29:19 2017 : Debug:   stats                    : yes
Fri Feb 10 14:29:19 2017 : Debug:   tcp                      : yes
Fri Feb 10 14:29:19 2017 : Debug:   threads                  : yes
Fri Feb 10 14:29:19 2017 : Debug:   tls                      : yes
Fri Feb 10 14:29:19 2017 : Debug:   unlang                   : yes
Fri Feb 10 14:29:19 2017 : Debug:   vmps                     : yes
Fri Feb 10 14:29:19 2017 : Debug:   developer                : no
Fri Feb 10 14:29:19 2017 : Debug: Server core libs:
Fri Feb 10 14:29:19 2017 : Debug:   freeradius-server        : 3.0.12
Fri Feb 10 14:29:19 2017 : Debug:   talloc                   : 2.0.*
Fri Feb 10 14:29:19 2017 : Debug:   ssl                      : 1.0.2k release
Fri Feb 10 14:29:19 2017 : Debug: Endianness:
Fri Feb 10 14:29:19 2017 : Debug:   little
Fri Feb 10 14:29:19 2017 : Debug: Compilation flags:
Fri Feb 10 14:29:19 2017 : Debug:   cppflags :
Fri Feb 10 14:29:19 2017 : Debug:   cflags   : -I. -Isrc -include
src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h
-include src/freeradius-devel/features.h -include
src/freeradius-devel/radpaths.h -fno-
Fri Feb 10 14:29:19 2017 : Debug:   ldflags  :
Fri Feb 10 14:29:19 2017 : Debug:   libs     : -lcrypto -lssl -ltalloc
-lnsl -lresolv -ldl -lpthread
Fri Feb 10 14:29:19 2017 : Debug:
Fri Feb 10 14:29:19 2017 : Info: FreeRADIUS Version 3.0.12
Fri Feb 10 14:29:19 2017 : Info: Copyright (C) 1999-2016 The
FreeRADIUS server project and contributors
Fri Feb 10 14:29:19 2017 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Fri Feb 10 14:29:19 2017 : Info: PARTICULAR PURPOSE
Fri Feb 10 14:29:19 2017 : Info: You may redistribute copies of
FreeRADIUS under the terms of the
Fri Feb 10 14:29:19 2017 : Info: GNU General Public License
Fri Feb 10 14:29:19 2017 : Info: For more information about these
matters, see the file named COPYRIGHT
Fri Feb 10 14:29:19 2017 : Info: Starting - reading configuration files ...
Fri Feb 10 14:29:19 2017 : Debug: including dictionary file
/usr/local/freeradius/share/freeradius/dictionary
Fri Feb 10 14:29:19 2017 : Debug: including dictionary file
/usr/local/freeradius/share/freeradius/dictionary.dhcp
Fri Feb 10 14:29:19 2017 : Debug: including dictionary file
/usr/local/freeradius/share/freeradius/dictionary.vqp
Fri Feb 10 14:29:19 2017 : Debug: including dictionary file
/etc/raddb/dictionary
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/radiusd.conf
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/proxy.conf
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/clients.conf
Fri Feb 10 14:29:19 2017 : Debug: including files in directory
/etc/raddb/mods-enabled/
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/cache_eap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/chap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/date
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/detail
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/digest
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/dhcp
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/dynamic_clients
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/eap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/echo
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/exec
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/expiration
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/expr
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/files
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/linelog
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/logintime
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/mschap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/ntlm_auth
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/pap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/passwd
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/preprocess
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/radutmp
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/replicate
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/soh
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/sradutmp
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/unix
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/unpack
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/mods-enabled/utf8
Fri Feb 10 14:29:19 2017 : Debug: including files in directory
/etc/raddb/policy.d/
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/abfab-tr
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/accounting
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/canonicalization
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/control
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/cui
Fri Feb 10 14:29:19 2017 : Debug: OPTIMIZING
(${policy.cui_require_operator_name} == yes) --> FALSE
Fri Feb 10 14:29:19 2017 : Debug: OPTIMIZING (no == yes) --> FALSE
Fri Feb 10 14:29:19 2017 : Debug: OPTIMIZING
(${policy.cui_require_operator_name} == yes) --> FALSE
Fri Feb 10 14:29:19 2017 : Debug: OPTIMIZING (no == yes) --> FALSE
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/debug
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/dhcp
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/eap
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/filter
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/moonshot-targeted-ids
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/policy.d/operator-name
Fri Feb 10 14:29:19 2017 : Debug: including files in directory
/etc/raddb/sites-enabled/
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:19 2017 : Debug: including configuration file
/etc/raddb/sites-enabled/inner-tunnel
Fri Feb 10 14:29:19 2017 : Debug: main {
Fri Feb 10 14:29:19 2017 : Debug:  security {
Fri Feb 10 14:29:19 2017 : Debug:   allow_core_dumps = no
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[462]: The
item 'max_attributes' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[480]: The
item 'reject_delay' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[500]: The
item 'status_server' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[510]: The
item 'allow_vulnerable_openssl' is defined, but is unused by the
configuration
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug: name = "radiusd"
Fri Feb 10 14:29:19 2017 : Debug: prefix = "/usr/local/freeradius"
Fri Feb 10 14:29:19 2017 : Debug: localstatedir = "/usr/local/freeradius/var"
Fri Feb 10 14:29:19 2017 : Debug: logdir =
"/usr/local/freeradius/var/log/radius"
Fri Feb 10 14:29:19 2017 : Debug: run_dir =
"/usr/local/freeradius/var/run/radiusd"
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[67]: The
item 'confdir' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[74]: The
item 'db_dir' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[108]: The
item 'libdir' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[119]: The
item 'pidfile' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[140]: The
item 'correct_escapes' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[194]: The
item 'max_request_time' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[213]: The
item 'cleanup_delay' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[250]: The
item 'hostname_lookups' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[372]: The
item 'checkrad' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[529]: The
item 'proxy_requests' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: main {
Fri Feb 10 14:29:19 2017 : Debug: name = "radiusd"
Fri Feb 10 14:29:19 2017 : Debug: prefix = "/usr/local/freeradius"
Fri Feb 10 14:29:19 2017 : Debug: localstatedir = "/usr/local/freeradius/var"
Fri Feb 10 14:29:19 2017 : Debug: sbindir = "/usr/local/freeradius/sbin"
Fri Feb 10 14:29:19 2017 : Debug: logdir =
"/usr/local/freeradius/var/log/radius"
Fri Feb 10 14:29:19 2017 : Debug: run_dir =
"/usr/local/freeradius/var/run/radiusd"
Fri Feb 10 14:29:19 2017 : Debug: libdir = "/usr/local/freeradius/lib"
Fri Feb 10 14:29:19 2017 : Debug: radacctdir =
"/usr/local/freeradius/var/log/radius/radacct"
Fri Feb 10 14:29:19 2017 : Debug: hostname_lookups = no
Fri Feb 10 14:29:19 2017 : Debug: max_request_time = 30
Fri Feb 10 14:29:19 2017 : Debug: cleanup_delay = 5
Fri Feb 10 14:29:19 2017 : Debug: max_requests = 16384
Fri Feb 10 14:29:19 2017 : Debug: pidfile =
"/usr/local/freeradius/var/run/radiusd/radiusd.pid"
Fri Feb 10 14:29:19 2017 : Debug: checkrad =
"/usr/local/freeradius/sbin/checkrad"
Fri Feb 10 14:29:19 2017 : Debug: debug_level = 0
Fri Feb 10 14:29:19 2017 : Debug: proxy_requests = yes
Fri Feb 10 14:29:19 2017 : Debug:  log {
Fri Feb 10 14:29:19 2017 : Debug:   stripped_names = no
Fri Feb 10 14:29:19 2017 : Debug:   auth = yes
Fri Feb 10 14:29:19 2017 : Debug:   auth_badpass = no
Fri Feb 10 14:29:19 2017 : Debug:   auth_goodpass = no
Fri Feb 10 14:29:19 2017 : Debug:   colourise = yes
Fri Feb 10 14:29:19 2017 : Debug:   msg_denied = "You are already
logged in - access denied"
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[268]: The
item 'destination' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[285]: The
item 'file' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[331]: The
item 'syslog_facility' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  resources {
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  security {
Fri Feb 10 14:29:19 2017 : Debug:   max_attributes = 200
Fri Feb 10 14:29:19 2017 : Debug:   reject_delay = 1.000000
Fri Feb 10 14:29:19 2017 : Debug:   status_server = yes
Fri Feb 10 14:29:19 2017 : Debug:   allow_vulnerable_openssl = "no"
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[67]: The
item 'confdir' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[74]: The
item 'db_dir' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Warning: /etc/raddb/radiusd.conf[140]: The
item 'correct_escapes' is defined, but is unused by the configuration
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: radiusd: #### Loading Realms and
Home Servers ####
Fri Feb 10 14:29:19 2017 : Debug:  proxy server {
Fri Feb 10 14:29:19 2017 : Debug:   retry_delay = 5
Fri Feb 10 14:29:19 2017 : Debug:   retry_count = 3
Fri Feb 10 14:29:19 2017 : Debug:   default_fallback = no
Fri Feb 10 14:29:19 2017 : Debug:   dead_time = 120
Fri Feb 10 14:29:19 2017 : Debug:   wake_all_if_all_dead = no
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  home_server localhost {
Fri Feb 10 14:29:19 2017 : Debug:   ipaddr = 127.0.0.1
Fri Feb 10 14:29:19 2017 : Debug:   port = 1812
Fri Feb 10 14:29:19 2017 : Debug:   type = "auth"
Fri Feb 10 14:29:19 2017 : Debug:   secret = "testing123"
Fri Feb 10 14:29:19 2017 : Debug:   response_window = 20.000000
Fri Feb 10 14:29:19 2017 : Debug:   response_timeouts = 1
Fri Feb 10 14:29:19 2017 : Debug:   max_outstanding = 65536
Fri Feb 10 14:29:19 2017 : Debug:   zombie_period = 40
Fri Feb 10 14:29:19 2017 : Debug:   status_check = "status-server"
Fri Feb 10 14:29:19 2017 : Debug:   ping_interval = 30
Fri Feb 10 14:29:19 2017 : Debug:   check_interval = 30
Fri Feb 10 14:29:19 2017 : Debug:   check_timeout = 4
Fri Feb 10 14:29:19 2017 : Debug:   num_answers_to_alive = 3
Fri Feb 10 14:29:19 2017 : Debug:   revive_interval = 120
Fri Feb 10 14:29:19 2017 : Debug:   limit {
Fri Feb 10 14:29:19 2017 : Debug:   max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:   max_requests = 0
Fri Feb 10 14:29:19 2017 : Debug:   lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:   idle_timeout = 0
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   coa {
Fri Feb 10 14:29:19 2017 : Debug:   irt = 2
Fri Feb 10 14:29:19 2017 : Debug:   mrt = 16
Fri Feb 10 14:29:19 2017 : Debug:   mrc = 5
Fri Feb 10 14:29:19 2017 : Debug:   mrd = 30
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  home_server_pool my_auth_failover {
Fri Feb 10 14:29:19 2017 : Debug: type = fail-over
Fri Feb 10 14:29:19 2017 : Debug: home_server = localhost
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  realm example.com {
Fri Feb 10 14:29:19 2017 : Debug: auth_pool = my_auth_failover
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug:  realm LOCAL {
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug: radiusd: #### Loading Clients ####
Fri Feb 10 14:29:19 2017 : Debug:  client 192.168.2.42 {
Fri Feb 10 14:29:19 2017 : Debug:   require_message_authenticator = no
Fri Feb 10 14:29:19 2017 : Debug:   secret = "#########blurred out#########"
Fri Feb 10 14:29:19 2017 : Debug:   shortname = "cisco-wlc"
Fri Feb 10 14:29:19 2017 : Debug:   limit {
Fri Feb 10 14:29:19 2017 : Debug:   max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:   lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:   idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Warning: No 'ipaddr' or 'ipv4addr' or
'ipv6addr' field found in client 192.168.2.42. Please fix your
configuration
Fri Feb 10 14:29:19 2017 : Warning: Support for old-style clients will
be removed in a future release
Fri Feb 10 14:29:19 2017 : Debug: Adding client 192.168.2.42/32
(192.168.2.42) to prefix tree 32
Fri Feb 10 14:29:19 2017 : Debug:  client localhost {
Fri Feb 10 14:29:19 2017 : Debug:   ipaddr = 127.0.0.1
Fri Feb 10 14:29:19 2017 : Debug:   require_message_authenticator = no
Fri Feb 10 14:29:19 2017 : Debug:   secret = "testing123"
Fri Feb 10 14:29:19 2017 : Debug:   nas_type = "other"
Fri Feb 10 14:29:19 2017 : Debug:   proto = "*"
Fri Feb 10 14:29:19 2017 : Debug:   limit {
Fri Feb 10 14:29:19 2017 : Debug:   max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:   lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:   idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug: Adding client 127.0.0.1/32
(127.0.0.1) to prefix tree 32
Fri Feb 10 14:29:19 2017 : Debug:  client localhost_ipv6 {
Fri Feb 10 14:29:19 2017 : Debug:   ipv6addr = ::1
Fri Feb 10 14:29:19 2017 : Debug:   require_message_authenticator = no
Fri Feb 10 14:29:19 2017 : Debug:   secret = "testing123"
Fri Feb 10 14:29:19 2017 : Debug:   limit {
Fri Feb 10 14:29:19 2017 : Debug:   max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:   lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:   idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  }
Fri Feb 10 14:29:19 2017 : Debug: Adding client ::1/128 (::1) to prefix tree 128
Fri Feb 10 14:29:19 2017 : Info: Debugger not attached
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = mschap
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = digest
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = eap
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = PAP
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = CHAP
Fri Feb 10 14:29:19 2017 : Debug:  # Creating Auth-Type = MS-CHAP
Fri Feb 10 14:29:19 2017 : Debug: radiusd: #### Instantiating modules ####
Fri Feb 10 14:29:19 2017 : Debug:  modules {
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_always with path:
/usr/local/freeradius/lib/rlm_always.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_always, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_always
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "reject" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always reject {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "reject"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "fail" from file
/etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always fail {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "fail"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "ok" from file
/etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always ok {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "ok"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "handled" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always handled {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "handled"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "invalid" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always invalid {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "invalid"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "userlock" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always userlock {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "userlock"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "notfound" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always notfound {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "notfound"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "noop" from file
/etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always noop {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "noop"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "updated" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   always updated {
Fri Feb 10 14:29:19 2017 : Debug:   rcode = "updated"
Fri Feb 10 14:29:19 2017 : Debug:   simulcount = 0
Fri Feb 10 14:29:19 2017 : Debug:   mpp = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_attr_filter with path:
/usr/local/freeradius/lib/rlm_attr_filter.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_attr_filter, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module
"attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter attr_filter.post-proxy {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/attr_filter/post-proxy"
Fri Feb 10 14:29:19 2017 : Debug:   key = "%{Realm}"
Fri Feb 10 14:29:19 2017 : Debug:   relaxed = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module
"attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter attr_filter.pre-proxy {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/attr_filter/pre-proxy"
Fri Feb 10 14:29:19 2017 : Debug:   key = "%{Realm}"
Fri Feb 10 14:29:19 2017 : Debug:   relaxed = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module
"attr_filter.access_reject" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter attr_filter.access_reject {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/attr_filter/access_reject"
Fri Feb 10 14:29:19 2017 : Debug:   key = "%{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   relaxed = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module
"attr_filter.access_challenge" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter attr_filter.access_challenge {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/attr_filter/access_challenge"
Fri Feb 10 14:29:19 2017 : Debug:   key = "%{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   relaxed = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module
"attr_filter.accounting_response" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter
attr_filter.accounting_response {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/attr_filter/accounting_response"
Fri Feb 10 14:29:19 2017 : Debug:   key = "%{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   relaxed = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_cache with path:
/usr/local/freeradius/lib/rlm_cache.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_cache, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_cache
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "cache_eap" from
file /etc/raddb/mods-enabled/cache_eap
Fri Feb 10 14:29:19 2017 : Debug:   cache cache_eap {
Fri Feb 10 14:29:19 2017 : Debug:   driver = "rlm_cache_rbtree"
Fri Feb 10 14:29:19 2017 : Debug:   key =
"%{%{control:State}:-%{%{reply:State}:-%{State}}}"
Fri Feb 10 14:29:19 2017 : Debug:   ttl = 15
Fri Feb 10 14:29:19 2017 : Debug:   max_entries = 0
Fri Feb 10 14:29:19 2017 : Debug:   epoch = 0
Fri Feb 10 14:29:19 2017 : Debug:   add_stats = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_chap with path:
/usr/local/freeradius/lib/rlm_chap.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_chap, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_chap
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "chap" from file
/etc/raddb/mods-enabled/chap
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_date with path:
/usr/local/freeradius/lib/rlm_date.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_date, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_date
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "date" from file
/etc/raddb/mods-enabled/date
Fri Feb 10 14:29:19 2017 : Debug:   date {
Fri Feb 10 14:29:19 2017 : Debug:   format = "%b %e %Y %H:%M:%S %Z"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_detail with path:
/usr/local/freeradius/lib/rlm_detail.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_detail, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_detail
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "detail" from
file /etc/raddb/mods-enabled/detail
Fri Feb 10 14:29:19 2017 : Debug:   detail {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Fri Feb 10 14:29:19 2017 : Debug:   header = "%t"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   locking = no
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   log_packet_header = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "auth_log" from
file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   detail auth_log {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
Fri Feb 10 14:29:19 2017 : Debug:   header = "%t"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   locking = no
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   log_packet_header = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "reply_log" from
file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   detail reply_log {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
Fri Feb 10 14:29:19 2017 : Debug:   header = "%t"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   locking = no
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   log_packet_header = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "pre_proxy_log"
from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   detail pre_proxy_log {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
Fri Feb 10 14:29:19 2017 : Debug:   header = "%t"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   locking = no
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   log_packet_header = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "post_proxy_log"
from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   detail post_proxy_log {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
Fri Feb 10 14:29:19 2017 : Debug:   header = "%t"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   locking = no
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   log_packet_header = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_digest with path:
/usr/local/freeradius/lib/rlm_digest.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_digest, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_digest
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "digest" from
file /etc/raddb/mods-enabled/digest
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_dhcp with path:
/usr/local/freeradius/lib/rlm_dhcp.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_dhcp, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_dhcp
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "dhcp" from file
/etc/raddb/mods-enabled/dhcp
Fri Feb 10 14:29:19 2017 : Debug: Adding values for DHCP-Parameter-Request-List
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 1 DHCP-Subnet-Mask
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 2 DHCP-Time-Offset
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 3 DHCP-Router-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 4 DHCP-Time-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 5 DHCP-IEN-116-Name-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 6 DHCP-Domain-Name-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 7 DHCP-Log-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 8 DHCP-Quotes-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 9 DHCP-LPR-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 10 DHCP-Impress-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 11 DHCP-RLP-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 12 DHCP-Hostname
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 13 DHCP-Boot-File-Size
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 14 DHCP-Merit-Dump-File
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 15 DHCP-Domain-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 16 DHCP-Swap-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 17 DHCP-Root-Path
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 18 DHCP-Bootp-Extensions-Path
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 19 DHCP-IP-Forward-Enable
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 20 DHCP-Source-Route-Enable
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 21 DHCP-Policy-Filter
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 22 DHCP-Max-Datagram-Reassembly-Size
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 23 DHCP-Default-IP-TTL
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 24 DHCP-Path-MTU-Aging-Timeout
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 25 DHCP-Path-MTU-Plateau-Table
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 26 DHCP-Interface-MTU-Size
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 27 DHCP-All-Subnets-Are-Local
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 28 DHCP-Broadcast-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 29 DHCP-Perform-Mask-Discovery
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 30 DHCP-Provide-Mask-To-Others
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 31 DHCP-Perform-Router-Discovery
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 32 DHCP-Router-Solicitation-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 33 DHCP-Static-Routes
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 34 DHCP-Trailer-Encapsulation
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 35 DHCP-ARP-Cache-Timeout
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 36 DHCP-Ethernet-Encapsulation
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 37 DHCP-Default-TCP-TTL
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 38 DHCP-Keep-Alive-Interval
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 39 DHCP-Keep-Alive-Garbage
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 40 DHCP-NIS-Domain-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 41 DHCP-NIS-Servers
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 42 DHCP-NTP-Servers
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 43 DHCP-Vendor
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 44 DHCP-NETBIOS-Name-Servers
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 45 DHCP-NETBIOS-Dgm-Dist-Servers
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 46 DHCP-NETBIOS-Node-Type
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 47 DHCP-NETBIOS
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 48 DHCP-X-Window-Font-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 49 DHCP-X-Window-Display-Mgr
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 50 DHCP-Requested-IP-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 51 DHCP-IP-Address-Lease-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 52 DHCP-Overload
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 53 DHCP-Message-Type
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 54 DHCP-DHCP-Server-Identifier
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 55 DHCP-Parameter-Request-List
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 56 DHCP-DHCP-Error-Message
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 57 DHCP-DHCP-Maximum-Msg-Size
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 58 DHCP-Renewal-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 59 DHCP-Rebinding-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 60 DHCP-Vendor-Class-Identifier
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 61 DHCP-Client-Identifier
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 62 DHCP-Netware-Domain-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 63 DHCP-Netware-Sub-Options
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 64 DHCP-NIS-Client-Domain-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 65 DHCP-NIS-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 66 DHCP-TFTP-Server-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 67 DHCP-Boot-File-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 68 DHCP-Home-Agent-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 69 DHCP-SMTP-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 70 DHCP-POP3-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 71 DHCP-NNTP-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 72 DHCP-WWW-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 73 DHCP-Finger-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 74 DHCP-IRC-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 75 DHCP-StreetTalk-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 76 DHCP-STDA-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 77 DHCP-User-Class
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 78 DHCP-Directory-Agent
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 79 DHCP-Service-Scope
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 80 DHCP-Rapid-Commit
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 81 DHCP-Client-FQDN
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 82 DHCP-Relay-Agent-Information
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 83 DHCP-iSNS
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 84
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 85 DHCP-NDS-Servers
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 86 DHCP-NDS-Tree-Name
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 87 DHCP-NDS-Context
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 88 DHCP-BCMS-Server-IPv4-FQDN
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 89 DHCP-BCMS-Server-IPv4-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 90 DHCP-Authentication
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 91 DHCP-Client-Last-Txn-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 92 DHCP-associated-ip
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 93 DHCP-Client-System
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 94 DHCP-Client-NDI
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 95 DHCP-LDAP
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 96
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 97 DHCP-UUID/GUID
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 98 DHCP-User-Auth
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 99 DHCP-GeoConf-Civic
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 100 DHCP-Timezone-Posix
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 101 DHCP-Timezone-Database
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 102
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 103
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 104
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 105
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 106
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 107
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 108
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 109
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 110
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 111
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 112 DHCP-Netinfo-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 113 DHCP-Netinfo-Tag
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 114 DHCP-URL
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 115
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 116 DHCP-Auto-Config
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 117 DHCP-Name-Service-Search
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 118 DHCP-Subnet-Selection-Option
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 119 DHCP-Domain-Search
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 120 DHCP-SIP-Servers-DHCP-Option
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 121 DHCP-Classless-Static-Route
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 122 DHCP-CCC
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 123 DHCP-GeoConf-Option
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 124 DHCP-V-I-Vendor-Class
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 125 DHCP-V-I-Vendor-Specific
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 126
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 127
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 128 DHCP-TFTP-Server-IP-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 129 DHCP-Call-Server-IP-address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 130 DHCP-Vendor-Discrimination-Str
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 131 DHCP-Remote-Stats-Svr-IP-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 132 DHCP-IEEE-802.1P-VLAN-ID
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 133 DHCP-IEEE-802.1Q-L2-Priority
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 134 DHCP-Diffserv-Code-Point
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 135 DHCP-HTTP-Proxy
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 136 DHCP-PANA-Agent
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 137 DHCP-LoST-Server
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 138 DHCP-CAPWAP-AC-IPv4-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 139 DHCP-MoS-IPv4-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 140 DHCP-MoS-IPv4-FQDN
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 141 DHCP-SIP-UA-Configuration-Service-Domains
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 142 DHCP-ANDSF-IPv4-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 143 DHCP-ANDSF-IPv6-Address
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 144
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 145
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 146
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 147
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 148
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 149
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 150 DHCP-TFTP-Server-IPv4-Address
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 151 DHCP-Query-Status-Code
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 152 DHCP-Query-Server-Base-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 153 DHCP-Query-Start-Time-Of-State
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 154 DHCP-Query-Start-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 155 DHCP-Query-End-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 156 DHCP-State
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 157 DHCP-Data-Source
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 158 DHCP-PCP-IPv4-Server-Address
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 159
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 160
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 161
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 162
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 163
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 164
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 165
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 166
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 167
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 168
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 169
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 170
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 171
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 172
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 173
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 174
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 175
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 176
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 177
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 178
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 179
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 180
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 181
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 182
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 183
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 184
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 185
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 186
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 187
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 188
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 189
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 190
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 191
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 192
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 193
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 194
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 195
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 196
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 197
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 198
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 199
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 200
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 201
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 202
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 203
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 204
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 205
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 206
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 207
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 208 DHCP-PXELINUX-Magic
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 209 DHCP-Packet-Format
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 210 DHCP-Path-Prefix
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 211 DHCP-Reboot-Time
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 212 DHCP-6RD
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 213 DHCP-Access-Network-Domain-Name
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 214
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 215
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 216
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 217
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 218
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 219
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 220 DHCP-Virtual-Subnet-Allocation
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 221 DHCP-Virtual-Subnet-Selection
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 222
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 223
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 224 DHCP-Site-specific-0
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 225 DHCP-Site-specific-1
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 226 DHCP-Site-specific-2
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 227 DHCP-Site-specific-3
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 228 DHCP-Site-specific-4
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 229 DHCP-Site-specific-5
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 230 DHCP-Site-specific-6
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 231 DHCP-Site-specific-7
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 232 DHCP-Site-specific-8
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 233 DHCP-Site-specific-9
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 234 DHCP-Site-specific-10
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 235 DHCP-Site-specific-11
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 236 DHCP-Site-specific-12
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 237 DHCP-Site-specific-13
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 238 DHCP-Site-specific-14
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 239 DHCP-Site-specific-15
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 240 DHCP-Site-specific-16
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 241 DHCP-Site-specific-17
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 242 DHCP-Site-specific-18
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 243 DHCP-Site-specific-19
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 244 DHCP-Site-specific-20
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 245 DHCP-Site-specific-21
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 246 DHCP-Site-specific-22
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 247 DHCP-Site-specific-23
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 248 DHCP-Site-specific-24
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 249 DHCP-Site-specific-25
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 250 DHCP-Site-specific-26
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 251 DHCP-Site-specific-27
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 252 DHCP-Site-specific-28
Fri Feb 10 14:29:19 2017 : Debug: Adding DHCP-Parameter-Request-List
value 253 DHCP-Site-specific-30
Fri Feb 10 14:29:19 2017 : Debug: No DHCP RFC space attribute at 254
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_dynamic_clients with
path: /usr/local/freeradius/lib/rlm_dynamic_clients.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_dynamic_clients, checking
if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_dynamic_clients
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "dynamic_clients"
from file /etc/raddb/mods-enabled/dynamic_clients
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap with path:
/usr/local/freeradius/lib/rlm_eap.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_eap, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_eap
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "eap" from file
/etc/raddb/mods-enabled/eap
Fri Feb 10 14:29:19 2017 : Debug:   eap {
Fri Feb 10 14:29:19 2017 : Debug:   default_eap_type = "md5"
Fri Feb 10 14:29:19 2017 : Debug:   timer_expire = 60
Fri Feb 10 14:29:19 2017 : Debug:   ignore_unknown_eap_types = no
Fri Feb 10 14:29:19 2017 : Debug:   cisco_accounting_username_bug = no
Fri Feb 10 14:29:19 2017 : Debug:   max_sessions = 16384
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_exec with path:
/usr/local/freeradius/lib/rlm_exec.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_exec, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_exec
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "echo" from file
/etc/raddb/mods-enabled/echo
Fri Feb 10 14:29:19 2017 : Debug:   exec echo {
Fri Feb 10 14:29:19 2017 : Debug:   wait = yes
Fri Feb 10 14:29:19 2017 : Debug:   program = "/bin/echo %{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   input_pairs = "request"
Fri Feb 10 14:29:19 2017 : Debug:   output_pairs = "reply"
Fri Feb 10 14:29:19 2017 : Debug:   shell_escape = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "exec" from file
/etc/raddb/mods-enabled/exec
Fri Feb 10 14:29:19 2017 : Debug:   exec {
Fri Feb 10 14:29:19 2017 : Debug:   wait = no
Fri Feb 10 14:29:19 2017 : Debug:   input_pairs = "request"
Fri Feb 10 14:29:19 2017 : Debug:   shell_escape = yes
Fri Feb 10 14:29:19 2017 : Debug:   timeout = 10
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_expiration with path:
/usr/local/freeradius/lib/rlm_expiration.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_expiration, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_expiration
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "expiration" from
file /etc/raddb/mods-enabled/expiration
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_expr with path:
/usr/local/freeradius/lib/rlm_expr.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_expr, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_expr
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "expr" from file
/etc/raddb/mods-enabled/expr
Fri Feb 10 14:29:19 2017 : Debug:   expr {
Fri Feb 10 14:29:19 2017 : Debug:   safe_characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_:
/äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_files with path:
/usr/local/freeradius/lib/rlm_files.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_files, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_files
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "files" from file
/etc/raddb/mods-enabled/files
Fri Feb 10 14:29:19 2017 : Debug:   files {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/etc/raddb/mods-config/files/authorize"
Fri Feb 10 14:29:19 2017 : Debug:   acctusersfile =
"/etc/raddb/mods-config/files/accounting"
Fri Feb 10 14:29:19 2017 : Debug:   preproxy_usersfile =
"/etc/raddb/mods-config/files/pre-proxy"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_linelog with path:
/usr/local/freeradius/lib/rlm_linelog.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_linelog, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_linelog
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "linelog" from
file /etc/raddb/mods-enabled/linelog
Fri Feb 10 14:29:19 2017 : Debug:   linelog {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/linelog"
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   syslog_severity = "info"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   format = "This is a log message
for %{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   reference =
"messages.%{%{reply:Packet-Type}:-default}"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "log_accounting"
from file /etc/raddb/mods-enabled/linelog
Fri Feb 10 14:29:19 2017 : Debug:   linelog log_accounting {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/linelog-accounting"
Fri Feb 10 14:29:19 2017 : Debug:   escape_filenames = no
Fri Feb 10 14:29:19 2017 : Debug:   syslog_severity = "info"
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   format = ""
Fri Feb 10 14:29:19 2017 : Debug:   reference =
"Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_logintime with path:
/usr/local/freeradius/lib/rlm_logintime.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_logintime, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_logintime
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "logintime" from
file /etc/raddb/mods-enabled/logintime
Fri Feb 10 14:29:19 2017 : Debug:   logintime {
Fri Feb 10 14:29:19 2017 : Debug:   minimum_timeout = 60
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_mschap with path:
/usr/local/freeradius/lib/rlm_mschap.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_mschap, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_mschap
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "mschap" from
file /etc/raddb/mods-enabled/mschap
Fri Feb 10 14:29:19 2017 : Debug:   mschap {
Fri Feb 10 14:29:19 2017 : Debug:   use_mppe = yes
Fri Feb 10 14:29:19 2017 : Debug:   require_encryption = no
Fri Feb 10 14:29:19 2017 : Debug:   require_strong = no
Fri Feb 10 14:29:19 2017 : Debug:   with_ntdomain_hack = yes
Fri Feb 10 14:29:19 2017 : Debug:    passchange {
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   allow_retry = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "ntlm_auth" from
file /etc/raddb/mods-enabled/ntlm_auth
Fri Feb 10 14:29:19 2017 : Debug:   exec ntlm_auth {
Fri Feb 10 14:29:19 2017 : Debug:   wait = yes
Fri Feb 10 14:29:19 2017 : Debug:   program = "/path/to/ntlm_auth
--request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name}
--password=%{User-Password}"
Fri Feb 10 14:29:19 2017 : Debug:   shell_escape = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_pap with path:
/usr/local/freeradius/lib/rlm_pap.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_pap, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_pap
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "pap" from file
/etc/raddb/mods-enabled/pap
Fri Feb 10 14:29:19 2017 : Debug:   pap {
Fri Feb 10 14:29:19 2017 : Debug:   normalise = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_passwd with path:
/usr/local/freeradius/lib/rlm_passwd.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_passwd, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_passwd
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "maclist" from
file /etc/raddb/mods-enabled/passwd
Fri Feb 10 14:29:19 2017 : Debug:   passwd maclist {
Fri Feb 10 14:29:19 2017 : Debug:   filename = "/etc/raddb/maclist"
Fri Feb 10 14:29:19 2017 : Debug:   format = "*User-Name:~mac-add"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = ":"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_nislike = yes
Fri Feb 10 14:29:19 2017 : Debug:   ignore_empty = yes
Fri Feb 10 14:29:19 2017 : Debug:   allow_multiple_keys = no
Fri Feb 10 14:29:19 2017 : Debug:   hash_size = 100
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "etc_passwd" from
file /etc/raddb/mods-enabled/passwd
Fri Feb 10 14:29:19 2017 : Debug:   passwd etc_passwd {
Fri Feb 10 14:29:19 2017 : Debug:   filename = "/etc/passwd"
Fri Feb 10 14:29:19 2017 : Debug:   format = "*User-Name:Crypt-Password:"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = ":"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_nislike = no
Fri Feb 10 14:29:19 2017 : Debug:   ignore_empty = yes
Fri Feb 10 14:29:19 2017 : Debug:   allow_multiple_keys = no
Fri Feb 10 14:29:19 2017 : Debug:   hash_size = 100
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_preprocess with path:
/usr/local/freeradius/lib/rlm_preprocess.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_preprocess, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_preprocess
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "preprocess" from
file /etc/raddb/mods-enabled/preprocess
Fri Feb 10 14:29:19 2017 : Debug:   preprocess {
Fri Feb 10 14:29:19 2017 : Debug:   huntgroups =
"/etc/raddb/mods-config/preprocess/huntgroups"
Fri Feb 10 14:29:19 2017 : Debug:   hints =
"/etc/raddb/mods-config/preprocess/hints"
Fri Feb 10 14:29:19 2017 : Debug:   with_ascend_hack = no
Fri Feb 10 14:29:19 2017 : Debug:   ascend_channels_per_line = 23
Fri Feb 10 14:29:19 2017 : Debug:   with_ntdomain_hack = no
Fri Feb 10 14:29:19 2017 : Debug:   with_specialix_jetstream_hack = no
Fri Feb 10 14:29:19 2017 : Debug:   with_cisco_vsa_hack = no
Fri Feb 10 14:29:19 2017 : Debug:   with_alvarion_vsa_hack = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_radutmp with path:
/usr/local/freeradius/lib/rlm_radutmp.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_radutmp, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_radutmp
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "radutmp" from
file /etc/raddb/mods-enabled/radutmp
Fri Feb 10 14:29:19 2017 : Debug:   radutmp {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/radutmp"
Fri Feb 10 14:29:19 2017 : Debug:   username = "%{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   case_sensitive = yes
Fri Feb 10 14:29:19 2017 : Debug:   check_with_nas = yes
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 384
Fri Feb 10 14:29:19 2017 : Debug:   caller_id = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_realm with path:
/usr/local/freeradius/lib/rlm_realm.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_realm, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_realm
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "IPASS" from file
/etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   realm IPASS {
Fri Feb 10 14:29:19 2017 : Debug:   format = "prefix"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = "/"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_default = no
Fri Feb 10 14:29:19 2017 : Debug:   ignore_null = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "suffix" from
file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   realm suffix {
Fri Feb 10 14:29:19 2017 : Debug:   format = "suffix"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = "@"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_default = no
Fri Feb 10 14:29:19 2017 : Debug:   ignore_null = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "realmpercent"
from file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   realm realmpercent {
Fri Feb 10 14:29:19 2017 : Debug:   format = "suffix"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = "%"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_default = no
Fri Feb 10 14:29:19 2017 : Debug:   ignore_null = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "ntdomain" from
file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   realm ntdomain {
Fri Feb 10 14:29:19 2017 : Debug:   format = "prefix"
Fri Feb 10 14:29:19 2017 : Debug:   delimiter = "\\"
Fri Feb 10 14:29:19 2017 : Debug:   ignore_default = no
Fri Feb 10 14:29:19 2017 : Debug:   ignore_null = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_replicate with path:
/usr/local/freeradius/lib/rlm_replicate.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_replicate, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_replicate
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "replicate" from
file /etc/raddb/mods-enabled/replicate
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_soh with path:
/usr/local/freeradius/lib/rlm_soh.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_soh, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_soh
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "soh" from file
/etc/raddb/mods-enabled/soh
Fri Feb 10 14:29:19 2017 : Debug:   soh {
Fri Feb 10 14:29:19 2017 : Debug:   dhcp = yes
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "sradutmp" from
file /etc/raddb/mods-enabled/sradutmp
Fri Feb 10 14:29:19 2017 : Debug:   radutmp sradutmp {
Fri Feb 10 14:29:19 2017 : Debug:   filename =
"/usr/local/freeradius/var/log/radius/sradutmp"
Fri Feb 10 14:29:19 2017 : Debug:   username = "%{User-Name}"
Fri Feb 10 14:29:19 2017 : Debug:   case_sensitive = yes
Fri Feb 10 14:29:19 2017 : Debug:   check_with_nas = yes
Fri Feb 10 14:29:19 2017 : Debug:   permissions = 420
Fri Feb 10 14:29:19 2017 : Debug:   caller_id = no
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_unix with path:
/usr/local/freeradius/lib/rlm_unix.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_unix, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_unix
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "unix" from file
/etc/raddb/mods-enabled/unix
Fri Feb 10 14:29:19 2017 : Debug:   unix {
Fri Feb 10 14:29:19 2017 : Debug:   radwtmp =
"/usr/local/freeradius/var/log/radius/radwtmp"
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug: Creating attribute Unix-Group
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_unpack with path:
/usr/local/freeradius/lib/rlm_unpack.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_unpack, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_unpack
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "unpack" from
file /etc/raddb/mods-enabled/unpack
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_utf8 with path:
/usr/local/freeradius/lib/rlm_utf8.so
Fri Feb 10 14:29:19 2017 : Debug: Loaded rlm_utf8, checking if it's valid
Fri Feb 10 14:29:19 2017 : Debug:   # Loaded module rlm_utf8
Fri Feb 10 14:29:19 2017 : Debug:   # Loading module "utf8" from file
/etc/raddb/mods-enabled/utf8
Fri Feb 10 14:29:19 2017 : Debug:   instantiate {
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "reject"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "fail" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "ok" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "handled"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "invalid"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "userlock"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "notfound"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "noop" from
file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "updated"
from file /etc/raddb/mods-enabled/always
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/attr_filter/post-proxy
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/attr_filter/pre-proxy
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"attr_filter.access_reject" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/attr_filter/access_reject
Fri Feb 10 14:29:19 2017 : Warning:
[/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item
"FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
Fri Feb 10 14:29:19 2017 : Warning:
[/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item
"FreeRADIUS-Response-Delay-USec" found in filter list for realm
"DEFAULT".
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"attr_filter.access_challenge" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/attr_filter/access_challenge
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"attr_filter.accounting_response" from file
/etc/raddb/mods-enabled/attr_filter
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/attr_filter/accounting_response
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "cache_eap"
from file /etc/raddb/mods-enabled/cache_eap
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_cache_rbtree with path:
/usr/local/freeradius/lib/rlm_cache_rbtree.so
Fri Feb 10 14:29:19 2017 : Debug: rlm_cache (cache_eap): Driver
rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "detail"
from file /etc/raddb/mods-enabled/detail
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "auth_log"
from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug: rlm_detail (auth_log):
'User-Password' suppressed, will not appear in detail output
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "reply_log"
from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"post_proxy_log" from file /etc/raddb/mods-enabled/detail.log
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "eap" from
file /etc/raddb/mods-enabled/eap
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_md5 with path:
/usr/local/freeradius/lib/rlm_eap_md5.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_md5
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_leap with path:
/usr/local/freeradius/lib/rlm_eap_leap.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_leap
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_gtc with path:
/usr/local/freeradius/lib/rlm_eap_gtc.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_gtc
Fri Feb 10 14:29:19 2017 : Debug:    gtc {
Fri Feb 10 14:29:19 2017 : Debug:     challenge = "Password: "
Fri Feb 10 14:29:19 2017 : Debug:     auth_type = "PAP"
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_tls with path:
/usr/local/freeradius/lib/rlm_eap_tls.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_tls
Fri Feb 10 14:29:19 2017 : Debug:    tls {
Fri Feb 10 14:29:19 2017 : Debug:     tls = "tls-common"
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:    tls-config tls-common {
Fri Feb 10 14:29:19 2017 : Debug:     verify_depth = 0
Fri Feb 10 14:29:19 2017 : Debug:     ca_path = "/etc/raddb/certs"
Fri Feb 10 14:29:19 2017 : Debug:     pem_file_type = yes
Fri Feb 10 14:29:19 2017 : Debug:     private_key_file =
"/etc/raddb/certs/server.pem"
Fri Feb 10 14:29:19 2017 : Debug:     certificate_file =
"/etc/raddb/certs/server.pem"
Fri Feb 10 14:29:19 2017 : Debug:     ca_file = "/etc/raddb/certs/ca.pem"
Fri Feb 10 14:29:19 2017 : Debug:     private_key_password =
"#########blurred out#########"
Fri Feb 10 14:29:19 2017 : Debug:     dh_file = "/etc/raddb/certs/dh"
Fri Feb 10 14:29:19 2017 : Debug:     fragment_size = 1024
Fri Feb 10 14:29:19 2017 : Debug:     include_length = yes
Fri Feb 10 14:29:19 2017 : Debug:     auto_chain = yes
Fri Feb 10 14:29:19 2017 : Debug:     check_crl = no
Fri Feb 10 14:29:19 2017 : Debug:     check_all_crl = no
Fri Feb 10 14:29:19 2017 : Debug:     cipher_list = "DEFAULT"
Fri Feb 10 14:29:19 2017 : Debug:     ecdh_curve = "prime256v1"
Fri Feb 10 14:29:19 2017 : Debug:     cache {
Fri Feb 10 14:29:19 2017 : Debug:     enable = yes
Fri Feb 10 14:29:19 2017 : Debug:     lifetime = 24
Fri Feb 10 14:29:19 2017 : Debug:     max_entries = 255
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     verify {
Fri Feb 10 14:29:19 2017 : Debug:     skip_if_ocsp_ok = no
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     ocsp {
Fri Feb 10 14:29:19 2017 : Debug:     enable = no
Fri Feb 10 14:29:19 2017 : Debug:     override_cert_url = yes
Fri Feb 10 14:29:19 2017 : Debug:     url = "http://127.0.0.1/ocsp/"
Fri Feb 10 14:29:19 2017 : Debug:     use_nonce = yes
Fri Feb 10 14:29:19 2017 : Debug:     timeout = 0
Fri Feb 10 14:29:19 2017 : Debug:     softfail = no
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_ttls with path:
/usr/local/freeradius/lib/rlm_eap_ttls.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_ttls
Fri Feb 10 14:29:19 2017 : Debug:    ttls {
Fri Feb 10 14:29:19 2017 : Debug:     tls = "tls-common"
Fri Feb 10 14:29:19 2017 : Debug:     default_eap_type = "md5"
Fri Feb 10 14:29:19 2017 : Debug:     copy_request_to_tunnel = no
Fri Feb 10 14:29:19 2017 : Debug:     use_tunneled_reply = no
Fri Feb 10 14:29:19 2017 : Debug:     virtual_server = "inner-tunnel"
Fri Feb 10 14:29:19 2017 : Debug:     include_length = yes
Fri Feb 10 14:29:19 2017 : Debug:     require_client_cert = no
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: tls: Using cached TLS configuration
from previous invocation
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_peap with path:
/usr/local/freeradius/lib/rlm_eap_peap.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_peap
Fri Feb 10 14:29:19 2017 : Debug:    peap {
Fri Feb 10 14:29:19 2017 : Debug:     tls = "tls-common"
Fri Feb 10 14:29:19 2017 : Debug:     default_eap_type = "mschapv2"
Fri Feb 10 14:29:19 2017 : Debug:     copy_request_to_tunnel = no
Fri Feb 10 14:29:19 2017 : Debug:     use_tunneled_reply = no
Fri Feb 10 14:29:19 2017 : Debug:     proxy_tunneled_request_as_eap = yes
Fri Feb 10 14:29:19 2017 : Debug:     virtual_server = "inner-tunnel"
Fri Feb 10 14:29:19 2017 : Debug:     soh = no
Fri Feb 10 14:29:19 2017 : Debug:     require_client_cert = no
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: tls: Using cached TLS configuration
from previous invocation
Fri Feb 10 14:29:19 2017 : Debug: Loading rlm_eap_mschapv2 with path:
/usr/local/freeradius/lib/rlm_eap_mschapv2.so
Fri Feb 10 14:29:19 2017 : Debug:    # Linked to sub-module rlm_eap_mschapv2
Fri Feb 10 14:29:19 2017 : Debug:    mschapv2 {
Fri Feb 10 14:29:19 2017 : Debug:     with_ntdomain_hack = no
Fri Feb 10 14:29:19 2017 : Debug:     send_error = no
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"expiration" from file /etc/raddb/mods-enabled/expiration
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "files"
from file /etc/raddb/mods-enabled/files
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/files/authorize
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/files/accounting
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/files/pre-proxy
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "linelog"
from file /etc/raddb/mods-enabled/linelog
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"log_accounting" from file /etc/raddb/mods-enabled/linelog
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "logintime"
from file /etc/raddb/mods-enabled/logintime
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "mschap"
from file /etc/raddb/mods-enabled/mschap
Fri Feb 10 14:29:19 2017 : Debug: rlm_mschap (mschap): using internal
authentication
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "pap" from
file /etc/raddb/mods-enabled/pap
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "maclist"
from file /etc/raddb/mods-enabled/passwd
Fri Feb 10 14:29:19 2017 : Debug: rlm_passwd: nfields: 2 keyfield
0(User-Name) listable: no
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"etc_passwd" from file /etc/raddb/mods-enabled/passwd
Fri Feb 10 14:29:19 2017 : Debug: rlm_passwd: nfields: 3 keyfield
0(User-Name) listable: no
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"preprocess" from file /etc/raddb/mods-enabled/preprocess
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/preprocess/huntgroups
Fri Feb 10 14:29:19 2017 : Debug: reading pairlist file
/etc/raddb/mods-config/preprocess/hints
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "IPASS"
from file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "suffix"
from file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module
"realmpercent" from file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:   # Instantiating module "ntdomain"
from file /etc/raddb/mods-enabled/realm
Fri Feb 10 14:29:19 2017 : Debug:  } # modules
Fri Feb 10 14:29:19 2017 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Feb 10 14:29:19 2017 : Debug: server { # from file /etc/raddb/radiusd.conf
Fri Feb 10 14:29:19 2017 : Debug: } # server
Fri Feb 10 14:29:19 2017 : Debug: server default { # from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:19 2017 : Debug:  authenticate {
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    pap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    chap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    mschap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   mschap
Fri Feb 10 14:29:19 2017 : Debug:   digest
Fri Feb 10 14:29:19 2017 : Debug:   eap
Fri Feb 10 14:29:19 2017 : Debug:  } # authenticate
Fri Feb 10 14:29:19 2017 : Debug:  authorize {
Fri Feb 10 14:29:19 2017 : Debug:   policy filter_username {
Fri Feb 10 14:29:19 2017 : Debug:    if (&User-Name) {
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ / /) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: User-Name contains whitespace'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@[^@]*@/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Multiple @ in User-Name'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /\.\./) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: User-Name contains multiple ..s'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@/ &&
!&User-Name =~ /@(.+)\.(.+)$/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm does not have at least one dot separator'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /\.$/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm ends with a dot'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@\./) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm begins with a dot'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   preprocess
Fri Feb 10 14:29:19 2017 : Debug:   chap
Fri Feb 10 14:29:19 2017 : Debug:   mschap
Fri Feb 10 14:29:19 2017 : Debug:   digest
Fri Feb 10 14:29:19 2017 : Debug:   suffix
Fri Feb 10 14:29:19 2017 : Debug:   if (&Called-Station-Id =~ /:test$/) {
Fri Feb 10 14:29:19 2017 : Debug:    eap
Fri Feb 10 14:29:19 2017 : Debug:    files
Fri Feb 10 14:29:19 2017 : Debug:    maclist
Fri Feb 10 14:29:19 2017 : Debug:    if (notfound) {
Fri Feb 10 14:29:19 2017 : Debug:     reject
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:    if (!&mac-add =~ /%{Calling-Station-ID}/) {
Fri Feb 10 14:29:19 2017 : Debug:     reject
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   files
Fri Feb 10 14:29:19 2017 : Warning: Ignoring "sql" (see
raddb/mods-available/README.rst)
Fri Feb 10 14:29:19 2017 : Warning: Ignoring "ldap" (see
raddb/mods-available/README.rst)
Fri Feb 10 14:29:19 2017 : Debug:   expiration
Fri Feb 10 14:29:19 2017 : Debug:   logintime
Fri Feb 10 14:29:19 2017 : Debug:   pap
Fri Feb 10 14:29:19 2017 : Debug:  } # authorize
Fri Feb 10 14:29:19 2017 : Debug:  preacct {
Fri Feb 10 14:29:19 2017 : Debug:   preprocess
Fri Feb 10 14:29:19 2017 : Warning:
/etc/raddb/policy.d/accounting[36]: Please change attribute reference
to '&Tmp-String-9 := ...'
Fri Feb 10 14:29:19 2017 : Debug:   policy acct_unique {
Fri Feb 10 14:29:19 2017 : Debug:    update {
Fri Feb 10 14:29:19 2017 : Debug:     &Tmp-String-9 := "ai:"
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:    if ("%{hex:&Class}" =~
/^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/)
{
Fri Feb 10 14:29:19 2017 : Debug:     update {
Fri Feb 10 14:29:19 2017 : Debug:      &Acct-Unique-Session-Id :=
"%{md5:%{1},%{Acct-Session-ID}}"
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:    else {
Fri Feb 10 14:29:19 2017 : Debug:     update {
Fri Feb 10 14:29:19 2017 : Debug:      &Acct-Unique-Session-Id :=
"%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}"
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   suffix
Fri Feb 10 14:29:19 2017 : Debug:   files
Fri Feb 10 14:29:19 2017 : Debug:  } # preacct
Fri Feb 10 14:29:19 2017 : Debug:  accounting {
Fri Feb 10 14:29:19 2017 : Debug:   detail
Fri Feb 10 14:29:19 2017 : Debug:   unix
Fri Feb 10 14:29:19 2017 : Debug:   exec
Fri Feb 10 14:29:19 2017 : Debug:   attr_filter.accounting_response
Fri Feb 10 14:29:19 2017 : Debug:  } # accounting
Fri Feb 10 14:29:19 2017 : Debug:  post-proxy {
Fri Feb 10 14:29:19 2017 : Debug:   eap
Fri Feb 10 14:29:19 2017 : Debug:  } # post-proxy
Fri Feb 10 14:29:19 2017 : Debug:  post-auth {
Fri Feb 10 14:29:19 2017 : Debug:   update {
Fri Feb 10 14:29:19 2017 : Debug:    &reply[*] += &session-state[*]
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   exec
Fri Feb 10 14:29:19 2017 : Debug:   policy remove_reply_message_if_eap {
Fri Feb 10 14:29:19 2017 : Debug:    if (&reply:EAP-Message &&
&reply:Reply-Message) {
Fri Feb 10 14:29:19 2017 : Debug:     update {
Fri Feb 10 14:29:19 2017 : Debug:      &reply:Reply-Message !* ANY
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:    else {
Fri Feb 10 14:29:19 2017 : Debug:     noop
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    attr_filter.access_reject
Fri Feb 10 14:29:19 2017 : Debug:    eap
Fri Feb 10 14:29:19 2017 : Debug:    policy remove_reply_message_if_eap {
Fri Feb 10 14:29:19 2017 : Debug:     if (&reply:EAP-Message &&
&reply:Reply-Message) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &reply:Reply-Message !* ANY
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     else {
Fri Feb 10 14:29:19 2017 : Debug:      noop
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  } # post-auth
Fri Feb 10 14:29:19 2017 : Debug: } # server default
Fri Feb 10 14:29:19 2017 : Debug: server inner-tunnel { # from file
/etc/raddb/sites-enabled/inner-tunnel
Fri Feb 10 14:29:19 2017 : Debug:  authenticate {
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    pap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    chap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    mschap
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   mschap
Fri Feb 10 14:29:19 2017 : Debug:   eap
Fri Feb 10 14:29:19 2017 : Debug:  } # authenticate
Fri Feb 10 14:29:19 2017 : Debug:  authorize {
Fri Feb 10 14:29:19 2017 : Debug:   policy filter_username {
Fri Feb 10 14:29:19 2017 : Debug:    if (&User-Name) {
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ / /) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: User-Name contains whitespace'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@[^@]*@/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Multiple @ in User-Name'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /\.\./) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: User-Name contains multiple ..s'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@/ &&
!&User-Name =~ /@(.+)\.(.+)$/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm does not have at least one dot separator'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /\.$/) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm ends with a dot'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:     if (&User-Name =~ /@\./) {
Fri Feb 10 14:29:19 2017 : Debug:      update {
Fri Feb 10 14:29:19 2017 : Debug:       &Module-Failure-Message +=
'Rejected: Realm begins with a dot'
Fri Feb 10 14:29:19 2017 : Debug:      }
Fri Feb 10 14:29:19 2017 : Debug:      reject
Fri Feb 10 14:29:19 2017 : Debug:     }
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   chap
Fri Feb 10 14:29:19 2017 : Debug:   mschap
Fri Feb 10 14:29:19 2017 : Debug:   suffix
Fri Feb 10 14:29:19 2017 : Debug:   update {
Fri Feb 10 14:29:19 2017 : Debug:    &control:Proxy-To-Realm := LOCAL
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:   eap
Fri Feb 10 14:29:19 2017 : Debug:   files
Fri Feb 10 14:29:19 2017 : Debug:   expiration
Fri Feb 10 14:29:19 2017 : Debug:   logintime
Fri Feb 10 14:29:19 2017 : Debug:   pap
Fri Feb 10 14:29:19 2017 : Debug:  } # authorize
Fri Feb 10 14:29:19 2017 : Debug:  session {
Fri Feb 10 14:29:19 2017 : Debug:   radutmp
Fri Feb 10 14:29:19 2017 : Debug:  } # session
Fri Feb 10 14:29:19 2017 : Debug:  post-proxy {
Fri Feb 10 14:29:19 2017 : Debug:   eap
Fri Feb 10 14:29:19 2017 : Debug:  } # post-proxy
Fri Feb 10 14:29:19 2017 : Debug:  post-auth {
Fri Feb 10 14:29:19 2017 : Debug:   group {
Fri Feb 10 14:29:19 2017 : Debug:    attr_filter.access_reject
Fri Feb 10 14:29:19 2017 : Debug:    update {
Fri Feb 10 14:29:19 2017 : Debug:
&outer.session-state:Module-Failure-Message := &Module-Failure-Message
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug:   }
Fri Feb 10 14:29:19 2017 : Debug:  } # post-auth
Fri Feb 10 14:29:19 2017 : Debug: } # server inner-tunnel
Fri Feb 10 14:29:19 2017 : Debug: Created signal pipe.  Read end FD 5,
write end FD 6
Fri Feb 10 14:29:19 2017 : Debug: radiusd: #### Opening IP addresses
and Ports ####
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth with path:
/usr/local/freeradius/lib/proto_auth.so
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth failed:
/usr/local/freeradius/lib/proto_auth.so: cannot open shared object
file: No such file or directory - No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: Loading library using linker search path(s)
Fri Feb 10 14:29:19 2017 : Debug: Defaults         : /lib:/usr/lib
Fri Feb 10 14:29:19 2017 : Debug: Failed with error: proto_auth.so:
cannot open shared object file: No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: listen {
Fri Feb 10 14:29:19 2017 : Debug:   type = "auth"
Fri Feb 10 14:29:19 2017 : Debug:   ipaddr = *
Fri Feb 10 14:29:19 2017 : Debug:   port = 0
Fri Feb 10 14:29:19 2017 : Debug:    limit {
Fri Feb 10 14:29:19 2017 : Debug:     max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:     lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:     idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_acct with path:
/usr/local/freeradius/lib/proto_acct.so
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_acct failed:
/usr/local/freeradius/lib/proto_acct.so: cannot open shared object
file: No such file or directory - No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: Loading library using linker search path(s)
Fri Feb 10 14:29:19 2017 : Debug: Defaults         : /lib:/usr/lib
Fri Feb 10 14:29:19 2017 : Debug: Failed with error: proto_acct.so:
cannot open shared object file: No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: listen {
Fri Feb 10 14:29:19 2017 : Debug:   type = "acct"
Fri Feb 10 14:29:19 2017 : Debug:   ipaddr = *
Fri Feb 10 14:29:19 2017 : Debug:   port = 0
Fri Feb 10 14:29:19 2017 : Debug:    limit {
Fri Feb 10 14:29:19 2017 : Debug:     max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:     lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:     idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth with path:
/usr/local/freeradius/lib/proto_auth.so
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth failed:
/usr/local/freeradius/lib/proto_auth.so: cannot open shared object
file: No such file or directory - No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: Loading library using linker search path(s)
Fri Feb 10 14:29:19 2017 : Debug: Defaults         : /lib:/usr/lib
Fri Feb 10 14:29:19 2017 : Debug: Failed with error: proto_auth.so:
cannot open shared object file: No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: listen {
Fri Feb 10 14:29:19 2017 : Debug:   type = "auth"
Fri Feb 10 14:29:19 2017 : Debug:   ipv6addr = ::
Fri Feb 10 14:29:19 2017 : Debug:   port = 0
Fri Feb 10 14:29:19 2017 : Debug:    limit {
Fri Feb 10 14:29:19 2017 : Debug:     max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:     lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:     idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_acct with path:
/usr/local/freeradius/lib/proto_acct.so
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_acct failed:
/usr/local/freeradius/lib/proto_acct.so: cannot open shared object
file: No such file or directory - No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: Loading library using linker search path(s)
Fri Feb 10 14:29:19 2017 : Debug: Defaults         : /lib:/usr/lib
Fri Feb 10 14:29:19 2017 : Debug: Failed with error: proto_acct.so:
cannot open shared object file: No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: listen {
Fri Feb 10 14:29:19 2017 : Debug:   type = "acct"
Fri Feb 10 14:29:19 2017 : Debug:   ipv6addr = ::
Fri Feb 10 14:29:19 2017 : Debug:   port = 0
Fri Feb 10 14:29:19 2017 : Debug:    limit {
Fri Feb 10 14:29:19 2017 : Debug:     max_connections = 16
Fri Feb 10 14:29:19 2017 : Debug:     lifetime = 0
Fri Feb 10 14:29:19 2017 : Debug:     idle_timeout = 30
Fri Feb 10 14:29:19 2017 : Debug:    }
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth with path:
/usr/local/freeradius/lib/proto_auth.so
Fri Feb 10 14:29:19 2017 : Debug: Loading proto_auth failed:
/usr/local/freeradius/lib/proto_auth.so: cannot open shared object
file: No such file or directory - No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: Loading library using linker search path(s)
Fri Feb 10 14:29:19 2017 : Debug: Defaults         : /lib:/usr/lib
Fri Feb 10 14:29:19 2017 : Debug: Failed with error: proto_auth.so:
cannot open shared object file: No such file or directory
Fri Feb 10 14:29:19 2017 : Debug: listen {
Fri Feb 10 14:29:19 2017 : Debug:   type = "auth"
Fri Feb 10 14:29:19 2017 : Debug:   ipaddr = 127.0.0.1
Fri Feb 10 14:29:19 2017 : Debug:   port = 18120
Fri Feb 10 14:29:19 2017 : Debug: }
Fri Feb 10 14:29:19 2017 : Debug: Listening on auth address * port
1812 bound to server default
Fri Feb 10 14:29:19 2017 : Debug: Listening on acct address * port
1813 bound to server default
Fri Feb 10 14:29:19 2017 : Debug: Listening on auth address :: port
1812 bound to server default
Fri Feb 10 14:29:19 2017 : Debug: Listening on acct address :: port
1813 bound to server default
Fri Feb 10 14:29:19 2017 : Debug: Listening on auth address 127.0.0.1
port 18120 bound to server inner-tunnel
Fri Feb 10 14:29:19 2017 : Debug: Opened new proxy socket 'proxy
address * port 34618'
Fri Feb 10 14:29:19 2017 : Debug: Listening on proxy address * port 34618
Fri Feb 10 14:29:19 2017 : Debug: Opened new proxy socket 'proxy
address :: port 55976'
Fri Feb 10 14:29:19 2017 : Debug: Listening on proxy address :: port 55976
Fri Feb 10 14:29:19 2017 : Info: Ready to process requests
Fri Feb 10 14:29:33 2017 : Debug: (0) Received Access-Request Id 98
from 192.168.2.42:32769 to 10.1.2.27:1812 length 241
Fri Feb 10 14:29:33 2017 : Debug: (0)   User-Name = "Mac284-1"
Fri Feb 10 14:29:33 2017 : Debug: (0)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:33 2017 : Debug: (0)   Location-Capable = Civix-Location
Fri Feb 10 14:29:33 2017 : Debug: (0)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:33 2017 : Debug: (0)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:33 2017 : Debug: (0)   NAS-Port = 1
Fri Feb 10 14:29:33 2017 : Debug: (0)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:33 2017 : Debug: (0)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:33 2017 : Debug: (0)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:33 2017 : Debug: (0)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:33 2017 : Debug: (0)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:33 2017 : Debug: (0)   Service-Type = Framed-User
Fri Feb 10 14:29:33 2017 : Debug: (0)   Framed-MTU = 1300
Fri Feb 10 14:29:33 2017 : Debug: (0)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:33 2017 : Debug: (0)   EAP-Message =
0x0201000d014d61633238342d31
Fri Feb 10 14:29:33 2017 : Debug: (0)   Message-Authenticator =
0x5ed75ae486e15c3d05ee4b37aececd94
Fri Feb 10 14:29:33 2017 : Debug: (0) session-state: No State attribute
Fri Feb 10 14:29:33 2017 : Debug: (0) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:33 2017 : Debug: (0)   authorize {
Fri Feb 10 14:29:33 2017 : Debug: (0)     policy filter_username {
Fri Feb 10 14:29:33 2017 : Debug: (0)       if (&User-Name) {
Fri Feb 10 14:29:33 2017 : Debug: (0)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:33 2017 : Debug: (0)       if (&User-Name)  {
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: (0)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:33 2017 : Debug: (0)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:33 2017 : Debug: (0)     } # policy filter_username = notfound
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [preprocess] = ok
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [chap] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [mschap] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [digest] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:33 2017 : Debug: (0) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:33 2017 : Debug: (0) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:33 2017 : Debug: (0) suffix: No such realm "NULL"
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [suffix] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:33 2017 : Debug: No matches
Fri Feb 10 14:29:33 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:33 2017 : Debug: (0)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:33 2017 : Debug: (0)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:33 2017 : Debug: (0)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: Peer sent EAP Response
(code 2) ID 1 length 13
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: EAP-Identity reply,
returning 'ok' so we can short-circuit the rest of authorize
Fri Feb 10 14:29:33 2017 : Debug: (0)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:33 2017 : Debug: (0)       [eap] = ok
Fri Feb 10 14:29:33 2017 : Debug: (0)     } # if (Called-Station-ID =~
/:test$/)  = ok
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [files] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [expiration] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [logintime] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:33 2017 : WARNING: (0) pap: No "known good" password
found for the user.  Not setting Auth-Type
Fri Feb 10 14:29:33 2017 : WARNING: (0) pap: Authentication will fail
unless a "known good" password is available
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [pap] = noop
Fri Feb 10 14:29:33 2017 : Debug: (0)   } # authorize = ok
Fri Feb 10 14:29:33 2017 : Debug: (0) Found Auth-Type = eap
Fri Feb 10 14:29:33 2017 : Debug: (0) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:33 2017 : Debug: (0)   authenticate {
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: Peer sent packet with
method EAP Identity (1)
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: Calling submodule eap_md5
to process data
Fri Feb 10 14:29:33 2017 : Debug: (0) eap_md5: Issuing MD5 Challenge
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: Sending EAP Request (code
1) ID 2 length 22
Fri Feb 10 14:29:33 2017 : Debug: (0) eap: EAP session adding
&reply:State = 0x0f3500170f37045e
Fri Feb 10 14:29:33 2017 : Debug: (0)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:33 2017 : Debug: (0)     [eap] = handled
Fri Feb 10 14:29:33 2017 : Debug: (0)   } # authenticate = handled
Fri Feb 10 14:29:33 2017 : Debug: (0) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:33 2017 : Debug: (0) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:33 2017 : Debug: (0) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:33 2017 : Debug: (0) session-state: Nothing to cache
Fri Feb 10 14:29:33 2017 : Debug: (0) Sent Access-Challenge Id 98 from
10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:33 2017 : Debug: (0)   EAP-Message =
0x010200160410f9d9e70b2c5efd62a1003635c5abfc34
Fri Feb 10 14:29:33 2017 : Debug: (0)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:33 2017 : Debug: (0)   State =
0x0f3500170f37045e5e6467b4ff0e74ed
Fri Feb 10 14:29:33 2017 : Debug: (0) Finished request
Fri Feb 10 14:29:33 2017 : Debug: Waking up in 4.9 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (1) Received Access-Request Id 99
from 192.168.2.42:32769 to 10.1.2.27:1812 length 252
Fri Feb 10 14:29:34 2017 : Debug: (1)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (1)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (1)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (1)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (1)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (1)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (1)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (1)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (1)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (1)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (1)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (1)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (1)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (1)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (1)   EAP-Message = 0x02020006030d
Fri Feb 10 14:29:34 2017 : Debug: (1)   State =
0x0f3500170f37045e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (1)   Message-Authenticator =
0x0960b7c1bf9d4ea5325269277f7ca2e8
Fri Feb 10 14:29:34 2017 : Debug: (1) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (1) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (1)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (1)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (1)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (1)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (1) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (1) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (1) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (1)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (1)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Peer sent EAP Response
(code 2) ID 2 length 6
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (1)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (1)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (1)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (1)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (1)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (1)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (1)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (1)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : WARNING: (1) pap: No "known good" password
found for the user.  Not setting Auth-Type
Fri Feb 10 14:29:34 2017 : WARNING: (1) pap: Authentication will fail
unless a "known good" password is available
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (1)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (1) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (1) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (1)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Expiring EAP session with
state 0x0f3500170f37045e
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Finished EAP session with
state 0x0f3500170f37045e
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Previous EAP request found
for state 0x0f3500170f37045e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Peer sent packet with
method EAP NAK (3)
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Found mutually acceptable
type TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (1) eap_tls: Initiating new EAP-TLS session
Fri Feb 10 14:29:34 2017 : Debug: (1) eap_tls: Flushing SSL sessions (of #0)
Fri Feb 10 14:29:34 2017 : Debug: (1) eap_tls: Setting verify mode to
require certificate from client
Fri Feb 10 14:29:34 2017 : Debug: (1) eap_tls: [eaptls start] = request
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: Sending EAP Request (code
1) ID 3 length 6
Fri Feb 10 14:29:34 2017 : Debug: (1) eap: EAP session adding
&reply:State = 0x0f3500170e360d5e
Fri Feb 10 14:29:34 2017 : Debug: (1)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (1)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (1)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (1) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (1) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (1) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (1) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (1) Sent Access-Challenge Id 99 from
10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (1)   EAP-Message = 0x010300060d20
Fri Feb 10 14:29:34 2017 : Debug: (1)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (1)   State =
0x0f3500170e360d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (1) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.9 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (2) Received Access-Request Id 100
from 192.168.2.42:32769 to 10.1.2.27:1812 length 398
Fri Feb 10 14:29:34 2017 : Debug: (2)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (2)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (2)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (2)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (2)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (2)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (2)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (2)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (2)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (2)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (2)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (2)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (2)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (2)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (2)   EAP-Message =
0x020300980d800000008e1603010089010000850301589db232748bacdc35e216089d7bcf5781bf7d62f3e3784e03bd20b62801f50900004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c02
Fri Feb 10 14:29:34 2017 : Debug: (2)   State =
0x0f3500170e360d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (2)   Message-Authenticator =
0xe031e479b6fb626bafc7e1f186cec3eb
Fri Feb 10 14:29:34 2017 : Debug: (2) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (2) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (2)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (2)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (2)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (2)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (2)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (2)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (2)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (2) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (2) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (2) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (2)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (2)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Peer sent EAP Response
(code 2) ID 3 length 152
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (2)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (2)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (2)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (2)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (2)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (2)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (2)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (2)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (2)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (2)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (2) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (2) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (2)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Expiring EAP session with
state 0x0f3500170e360d5e
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Finished EAP session with
state 0x0f3500170e360d5e
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Previous EAP request found
for state 0x0f3500170e360d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: Peer sent flags --L
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: Peer indicated complete
TLS record size will be 142 bytes
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: Got complete TLS record
(142 bytes)
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: [eaptls verify] = length included
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: (other): before/accept
initialization
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept:
before/accept initialization
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: <<< recv TLS 1.0
Handshake [length 0089], ClientHello
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 read
client hello A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: >>> send TLS 1.0
Handshake [length 0059], ServerHello
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 write
server hello A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: >>> send TLS 1.0
Handshake [length 07aa], Certificate
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 write
certificate A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: >>> send TLS 1.0
Handshake [length 014b], ServerKeyExchange
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 write
key exchange A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: >>> send TLS 1.0
Handshake [length 00b9], CertificateRequest
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 write
certificate request A
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: SSLv3 flush data
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: Need to
read more data: SSLv3 read client certificate A
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: TLS_accept: Need to
read more data: SSLv3 read client certificate A
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: In SSL Handshake Phase
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: In SSL Accept mode
Fri Feb 10 14:29:34 2017 : Debug: (2) eap_tls: [eaptls process] = handled
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: Sending EAP Request (code
1) ID 4 length 1004
Fri Feb 10 14:29:34 2017 : Debug: (2) eap: EAP session adding
&reply:State = 0x0f3500170d310d5e
Fri Feb 10 14:29:34 2017 : Debug: (2)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (2)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (2)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (2) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (2) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (2) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (2) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (2) Sent Access-Challenge Id 100
from 10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (2)   EAP-Message =
0x010403ec0dc000000a1b16030100590200005503018247d431d6c7096b532cafabd8fc07e077964a30e1554b2098b9b12722d0523120485a74c7392861c29eb7e30d7e8e243c46b048d4db4769b777630bad685
Fri Feb 10 14:29:34 2017 : Debug: (2)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (2)   State =
0x0f3500170d310d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (2) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.9 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (3) Received Access-Request Id 101
from 192.168.2.42:32769 to 10.1.2.27:1812 length 252
Fri Feb 10 14:29:34 2017 : Debug: (3)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (3)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (3)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (3)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (3)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (3)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (3)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (3)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (3)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (3)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (3)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (3)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (3)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (3)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (3)   EAP-Message = 0x020400060d00
Fri Feb 10 14:29:34 2017 : Debug: (3)   State =
0x0f3500170d310d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (3)   Message-Authenticator =
0xfda6396b0660592a6a1cbeb369d7bae1
Fri Feb 10 14:29:34 2017 : Debug: (3) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (3) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (3)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (3)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (3)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (3)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (3)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (3)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (3)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (3) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (3) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (3) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (3)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (3)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Peer sent EAP Response
(code 2) ID 4 length 6
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (3)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (3)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (3)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (3)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (3)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (3)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (3)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (3)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (3)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (3)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (3) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (3) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (3)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Expiring EAP session with
state 0x0f3500170d310d5e
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Finished EAP session with
state 0x0f3500170d310d5e
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Previous EAP request found
for state 0x0f3500170d310d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (3) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (3) eap_tls: Peer sent flags ---
Fri Feb 10 14:29:34 2017 : Debug: (3) eap_tls: Peer ACKed our handshake fragment
Fri Feb 10 14:29:34 2017 : Debug: (3) eap_tls: [eaptls verify] = request
Fri Feb 10 14:29:34 2017 : Debug: (3) eap_tls: [eaptls process] = handled
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: Sending EAP Request (code
1) ID 5 length 1004
Fri Feb 10 14:29:34 2017 : Debug: (3) eap: EAP session adding
&reply:State = 0x0f3500170c300d5e
Fri Feb 10 14:29:34 2017 : Debug: (3)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (3)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (3)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (3) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (3) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (3) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (3) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (3) Sent Access-Challenge Id 101
from 10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (3)   EAP-Message =
0x010503ec0dc000000a1b6a659dcfe39398cfd9c7305d004b5811091a9b899ee9b7a4819aa20ec49b1337c6e1d01b9e96cebec78d7126da71b4cf35fa43ea2403b4ee8b9e4977e98fd081db3845bc77321dfad9c
Fri Feb 10 14:29:34 2017 : Debug: (3)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (3)   State =
0x0f3500170c300d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (3) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.9 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (4) Received Access-Request Id 102
from 192.168.2.42:32769 to 10.1.2.27:1812 length 252
Fri Feb 10 14:29:34 2017 : Debug: (4)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (4)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (4)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (4)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (4)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (4)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (4)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (4)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (4)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (4)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (4)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (4)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (4)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (4)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (4)   EAP-Message = 0x020500060d00
Fri Feb 10 14:29:34 2017 : Debug: (4)   State =
0x0f3500170c300d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (4)   Message-Authenticator =
0x1625241e783bad827ceddb22922aefa1
Fri Feb 10 14:29:34 2017 : Debug: (4) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (4) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (4)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (4)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (4)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (4)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (4)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (4)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (4)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (4) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (4) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (4) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (4)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (4)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Peer sent EAP Response
(code 2) ID 5 length 6
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (4)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (4)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (4)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (4)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (4)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (4)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (4)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (4)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (4)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (4)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (4) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (4) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (4)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Expiring EAP session with
state 0x0f3500170c300d5e
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Finished EAP session with
state 0x0f3500170c300d5e
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Previous EAP request found
for state 0x0f3500170c300d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (4) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (4) eap_tls: Peer sent flags ---
Fri Feb 10 14:29:34 2017 : Debug: (4) eap_tls: Peer ACKed our handshake fragment
Fri Feb 10 14:29:34 2017 : Debug: (4) eap_tls: [eaptls verify] = request
Fri Feb 10 14:29:34 2017 : Debug: (4) eap_tls: [eaptls process] = handled
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: Sending EAP Request (code
1) ID 6 length 609
Fri Feb 10 14:29:34 2017 : Debug: (4) eap: EAP session adding
&reply:State = 0x0f3500170b330d5e
Fri Feb 10 14:29:34 2017 : Debug: (4)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (4)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (4)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (4) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (4) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (4) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (4) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (4) Sent Access-Challenge Id 102
from 10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (4)   EAP-Message =
0x010602610d8000000a1bf72d066d93329bb942fb06862c2fec2ad76c4157b0754ad679a5e2f689478c827dfd4dd53ad9f59f6404326d34ce7ad3d9d4665ea116bd4fedbf129944c8ad1048bfbfb88824da246b1
Fri Feb 10 14:29:34 2017 : Debug: (4)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (4)   State =
0x0f3500170b330d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (4) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.9 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (5) Received Access-Request Id 103
from 192.168.2.42:32769 to 10.1.2.27:1812 length 1532
Fri Feb 10 14:29:34 2017 : Debug: (5)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (5)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (5)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (5)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (5)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (5)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (5)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (5)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (5)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (5)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (5)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (5)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (5)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (5)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (5)   EAP-Message =
0x020604fc0dc00000094416030107ae0b0007aa0007a70003d3308203cf308202b7a0030201020202016e300d06092a864886f70d01010405003081a6310b3009060355040613024445311b30190603550408131
Fri Feb 10 14:29:34 2017 : Debug: (5)   State =
0x0f3500170b330d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (5)   Message-Authenticator =
0x8645015c7ba519503ab0fbcaf40b9d00
Fri Feb 10 14:29:34 2017 : Debug: (5) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (5) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (5)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (5)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (5)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (5)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (5)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (5)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (5)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (5) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (5) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (5) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (5)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (5)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Peer sent EAP Response
(code 2) ID 6 length 1276
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (5)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (5)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (5)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (5)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (5)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (5)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (5)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (5)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (5)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (5)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (5) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (5) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (5)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Expiring EAP session with
state 0x0f3500170b330d5e
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Finished EAP session with
state 0x0f3500170b330d5e
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Previous EAP request found
for state 0x0f3500170b330d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: Peer sent flags -ML
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: Peer indicated complete
TLS record size will be 2372 bytes
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: Expecting 2 TLS record fragments
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: Got first TLS record
fragment (1266 bytes).  Peer indicated more fragments to follow
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: [eaptls verify] = first fragment
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: ACKing Peer's TLS record fragment
Fri Feb 10 14:29:34 2017 : Debug: (5) eap_tls: [eaptls process] = handled
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: Sending EAP Request (code
1) ID 7 length 6
Fri Feb 10 14:29:34 2017 : Debug: (5) eap: EAP session adding
&reply:State = 0x0f3500170a320d5e
Fri Feb 10 14:29:34 2017 : Debug: (5)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (5)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (5)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (5) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (5) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (5) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (5) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (5) Sent Access-Challenge Id 103
from 10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (5)   EAP-Message = 0x010700060d00
Fri Feb 10 14:29:34 2017 : Debug: (5)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (5)   State =
0x0f3500170a320d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (5) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.8 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (6) Received Access-Request Id 104
from 192.168.2.42:32769 to 10.1.2.27:1812 length 1366
Fri Feb 10 14:29:34 2017 : Debug: (6)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (6)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (6)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (6)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (6)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (6)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (6)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (6)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (6)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (6)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (6)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (6)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (6)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (6)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (6)   EAP-Message =
0x020704580d007565727474656d626572673111300f060355040713084672656962757267312d302b060355040a13244d61782d506c616e636b2d496e73746974757420662e20496d6d756e62696f6c6f6769653
Fri Feb 10 14:29:34 2017 : Debug: (6)   State =
0x0f3500170a320d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (6)   Message-Authenticator =
0x558ef43e9ca069297b5657c7f2d31dd5
Fri Feb 10 14:29:34 2017 : Debug: (6) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (6) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (6)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (6)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (6)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (6)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (6)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (6)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (6)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (6) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (6) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (6) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (6)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (6)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Peer sent EAP Response
(code 2) ID 7 length 1112
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (6)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (6)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (6)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (6)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (6)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (6)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (6)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (6)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (6)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (6)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (6) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (6) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (6)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Expiring EAP session with
state 0x0f3500170a320d5e
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Finished EAP session with
state 0x0f3500170a320d5e
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Previous EAP request found
for state 0x0f3500170a320d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Peer sent flags ---
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Got final TLS record
fragment (1106 bytes)
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: [eaptls verify] = ok
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Done initial handshake
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: <<< recv TLS 1.0
Handshake [length 07ae], Certificate
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Creating attributes
from certificate OIDs
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:   TLS-Cert-Serial :=
"98b6bd1078043d7c"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:   TLS-Cert-Expiration
:= "180803113510Z"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:   TLS-Cert-Subject :=
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:   TLS-Cert-Issuer :=
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:   TLS-Cert-Common-Name
:= "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: chain-depth   : 1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: error         : 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: identity      : Mac284-1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: common name   :
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: subject       :
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: issuer        :
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: verify return : 1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: Creating attributes
from certificate OIDs
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-Serial := "016e"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-Expiration := "170303122029Z"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-Subject := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-Issuer := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-Common-Name := "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls:
TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Client
Authentication"
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: chain-depth   : 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: error         : 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: identity      : Mac284-1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: common name   : Mac284-1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: subject       :
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: issuer        :
#########blurred out#########
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: verify return : 1
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 read
client certificate A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: <<< recv TLS 1.0
Handshake [length 0046], ClientKeyExchange
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 read
client key exchange A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: <<< recv TLS 1.0
Handshake [length 0106], CertificateVerify
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 read
certificate verify A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: <<< recv TLS 1.0
ChangeCipherSpec [length 0001]
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: <<< recv TLS 1.0
Handshake [length 0010], Finished
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 read finished A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: >>> send TLS 1.0
ChangeCipherSpec [length 0001]
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 write
change cipher spec A
Fri Feb 10 14:29:34 2017 : Debug: Ignoring cbtls_msg call with pseudo
content type 256, version 0
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: >>> send TLS 1.0
Handshake [length 0010], Finished
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 write
finished A
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: TLS_accept: SSLv3 flush data
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: (other): SSL
negotiation finished successfully
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: SSL Connection Established
Fri Feb 10 14:29:34 2017 : Debug: (6) eap_tls: [eaptls process] = handled
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: Sending EAP Request (code
1) ID 8 length 69
Fri Feb 10 14:29:34 2017 : Debug: (6) eap: EAP session adding
&reply:State = 0x0f350017093d0d5e
Fri Feb 10 14:29:34 2017 : Debug: (6)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (6)     [eap] = handled
Fri Feb 10 14:29:34 2017 : Debug: (6)   } # authenticate = handled
Fri Feb 10 14:29:34 2017 : Debug: (6) Using Post-Auth-Type Challenge
Fri Feb 10 14:29:34 2017 : Debug: (6) Post-Auth-Type sub-section not
found.  Ignoring.
Fri Feb 10 14:29:34 2017 : Debug: (6) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (6) session-state: Nothing to cache
Fri Feb 10 14:29:34 2017 : Debug: (6) Sent Access-Challenge Id 104
from 10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (6)   EAP-Message =
0x010800450d800000003b14030100010116030100305cadcd0b17fc7fbcae71a325211171c402d735f87a58da58a4ae39c48cbdfb3262afd2c9fadca4883eb50e3458dfde2d
Fri Feb 10 14:29:34 2017 : Debug: (6)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (6)   State =
0x0f350017093d0d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (6) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.8 seconds.
Fri Feb 10 14:29:34 2017 : Debug: (7) Received Access-Request Id 105
from 192.168.2.42:32769 to 10.1.2.27:1812 length 252
Fri Feb 10 14:29:34 2017 : Debug: (7)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (7)   Chargeable-User-Identity = 0x00
Fri Feb 10 14:29:34 2017 : Debug: (7)   Location-Capable = Civix-Location
Fri Feb 10 14:29:34 2017 : Debug: (7)   Calling-Station-Id = "00236c94ed49"
Fri Feb 10 14:29:34 2017 : Debug: (7)   Called-Station-Id = "34a84edc9b40:test"
Fri Feb 10 14:29:34 2017 : Debug: (7)   NAS-Port = 1
Fri Feb 10 14:29:34 2017 : Debug: (7)   Cisco-AVPair =
"audit-session-id=c0a8022a0006e4f3589db219"
Fri Feb 10 14:29:34 2017 : Debug: (7)   Acct-Session-Id =
"589db219/00:23:6c:94:ed:49/90021"
Fri Feb 10 14:29:34 2017 : Debug: (7)   NAS-IP-Address = 192.168.2.42
Fri Feb 10 14:29:34 2017 : Debug: (7)   NAS-Identifier = "cisco-wlc"
Fri Feb 10 14:29:34 2017 : Debug: (7)   Airespace-Wlan-Id = 6
Fri Feb 10 14:29:34 2017 : Debug: (7)   Service-Type = Framed-User
Fri Feb 10 14:29:34 2017 : Debug: (7)   Framed-MTU = 1300
Fri Feb 10 14:29:34 2017 : Debug: (7)   NAS-Port-Type = Wireless-802.11
Fri Feb 10 14:29:34 2017 : Debug: (7)   EAP-Message = 0x020800060d00
Fri Feb 10 14:29:34 2017 : Debug: (7)   State =
0x0f350017093d0d5e5e6467b4ff0e74ed
Fri Feb 10 14:29:34 2017 : Debug: (7)   Message-Authenticator =
0x7c08f2055d14d1c64ea80cbdd58ca75e
Fri Feb 10 14:29:34 2017 : Debug: (7) session-state: No cached attributes
Fri Feb 10 14:29:34 2017 : Debug: (7) # Executing section authorize
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (7)   authorize {
Fri Feb 10 14:29:34 2017 : Debug: (7)     policy filter_username {
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (&User-Name) {
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (&User-Name)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (&User-Name)  {
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ / /) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ / /)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /@[^@]*@/ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~
/@[^@]*@/ )  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /\.\./ ) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /\.\./
)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if ((&User-Name =~ /@/)
&& (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /\.$/)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /\.$/)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /@\./)  {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: (7)         if (&User-Name =~ /@\./)
  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)       } # if (&User-Name)  = notfound
Fri Feb 10 14:29:34 2017 : Debug: (7)     } # policy filter_username = notfound
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from preprocess (rlm_preprocess)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [preprocess] = ok
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from chap (rlm_chap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [chap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from mschap (rlm_mschap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [mschap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from digest (rlm_digest)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [digest] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (7) suffix: Checking for suffix after "@"
Fri Feb 10 14:29:34 2017 : Debug: (7) suffix: No '@' in User-Name =
"Mac284-1", looking up realm NULL
Fri Feb 10 14:29:34 2017 : Debug: (7) suffix: No such realm "NULL"
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from suffix (rlm_realm)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [suffix] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     if (Called-Station-ID =~ /:test$/) {
Fri Feb 10 14:29:34 2017 : Debug: No matches
Fri Feb 10 14:29:34 2017 : Debug: Adding 1 matches
Fri Feb 10 14:29:34 2017 : Debug: (7)     if (Called-Station-ID =~
/:test$/)  -> TRUE
Fri Feb 10 14:29:34 2017 : Debug: (7)     if (Called-Station-ID =~ /:test$/)  {
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Peer sent EAP Response
(code 2) ID 8 length 6
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: No EAP Start, assuming it's
an on-going EAP conversation
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (7)       [eap] = updated
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (7)       [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
calling maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (7)       modsingle[authorize]:
returned from maclist (rlm_passwd)
Fri Feb 10 14:29:34 2017 : Debug: (7)       [maclist] = ok
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (notfound) {
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (notfound)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)       if ( mac-add !~
/%{Calling-Station-ID}/i) {
Fri Feb 10 14:29:34 2017 : ERROR: (7)       Failed retrieving values
required to evaluate condition
Fri Feb 10 14:29:34 2017 : Debug: (7)     } # if (Called-Station-ID =~
/:test$/)  = updated
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from files (rlm_files)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [files] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from expiration (rlm_expiration)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [expiration] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from logintime (rlm_logintime)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [logintime] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
calling pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authorize]:
returned from pap (rlm_pap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [pap] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)   } # authorize = updated
Fri Feb 10 14:29:34 2017 : Debug: (7) Found Auth-Type = eap
Fri Feb 10 14:29:34 2017 : Debug: (7) # Executing group from file
/etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (7)   authenticate {
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authenticate]:
calling eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Expiring EAP session with
state 0x0f350017093d0d5e
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Finished EAP session with
state 0x0f350017093d0d5e
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Previous EAP request found
for state 0x0f350017093d0d5e, released from the list
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Peer sent packet with
method EAP TLS (13)
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Calling submodule eap_tls
to process data
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: Continuing EAP-TLS
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: Peer sent flags ---
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: Peer ACKed our
handshake fragment.  handshake is finished
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: [eaptls verify] = success
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: [eaptls process] = success
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Cert-Serial := "98b6bd1078043d7c"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Cert-Expiration := "180803113510Z"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Cert-Subject := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Cert-Issuer := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Cert-Common-Name := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-Serial := "016e"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-Expiration := "170303122029Z"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-Subject := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-Issuer := "#########blurred out#########"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-Common-Name := "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls:     caching
TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Client
Authentication"
Fri Feb 10 14:29:34 2017 : Debug: (7) eap_tls: Failed to find
'persist_dir' in TLS configuration.  Session will not be cached on
disk.
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Sending EAP Success (code
3) ID 8 length 4
Fri Feb 10 14:29:34 2017 : Debug: (7) eap: Freeing handler
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[authenticate]:
returned from eap (rlm_eap)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [eap] = ok
Fri Feb 10 14:29:34 2017 : Debug: (7)   } # authenticate = ok
Fri Feb 10 14:29:34 2017 : Debug: (7) # Executing section post-auth
from file /etc/raddb/sites-enabled/default
Fri Feb 10 14:29:34 2017 : Debug: (7)   post-auth {
Fri Feb 10 14:29:34 2017 : Debug: (7)     update {
Fri Feb 10 14:29:34 2017 : Debug: (7)       No attributes updated
Fri Feb 10 14:29:34 2017 : Debug: (7)     } # update = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[post-auth]:
calling exec (rlm_exec)
Fri Feb 10 14:29:34 2017 : Debug: (7)     modsingle[post-auth]:
returned from exec (rlm_exec)
Fri Feb 10 14:29:34 2017 : Debug: (7)     [exec] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     policy remove_reply_message_if_eap {
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (&reply:EAP-Message &&
&reply:Reply-Message) {
Fri Feb 10 14:29:34 2017 : Debug: (7)       if (&reply:EAP-Message &&
&reply:Reply-Message)  -> FALSE
Fri Feb 10 14:29:34 2017 : Debug: (7)       else {
Fri Feb 10 14:29:34 2017 : Debug: (7)         modsingle[post-auth]:
calling noop (rlm_always)
Fri Feb 10 14:29:34 2017 : Debug: (7)         modsingle[post-auth]:
returned from noop (rlm_always)
Fri Feb 10 14:29:34 2017 : Debug: (7)         [noop] = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)       } # else = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)     } # policy
remove_reply_message_if_eap = noop
Fri Feb 10 14:29:34 2017 : Debug: (7)   } # post-auth = noop
Fri Feb 10 14:29:34 2017 : Auth: (7) Login OK: [Mac284-1] (from client
cisco-wlc port 1 cli 00236c94ed49)
Fri Feb 10 14:29:34 2017 : Debug: (7) Sent Access-Accept Id 105 from
10.1.2.27:1812 to 192.168.2.42:32769 length 0
Fri Feb 10 14:29:34 2017 : Debug: (7)   MS-MPPE-Recv-Key =
0x19d26b0c30c438c23e91f0e1a27d0b5057c367169ac6527cbbe938f615c24b27
Fri Feb 10 14:29:34 2017 : Debug: (7)   MS-MPPE-Send-Key =
0x8ac9696835bbe7490d724d3a380aa10cf0d301723197e601105d4b32b330ed37
Fri Feb 10 14:29:34 2017 : Debug: (7)   EAP-Message = 0x03080004
Fri Feb 10 14:29:34 2017 : Debug: (7)   Message-Authenticator =
0x00000000000000000000000000000000
Fri Feb 10 14:29:34 2017 : Debug: (7)   User-Name = "Mac284-1"
Fri Feb 10 14:29:34 2017 : Debug: (7) Finished request
Fri Feb 10 14:29:34 2017 : Debug: Waking up in 4.8 seconds.
Fri Feb 10 14:29:38 2017 : Debug: (0) Cleaning up request packet ID 98
with timestamp +14
Fri Feb 10 14:29:39 2017 : Debug: (1) Cleaning up request packet ID 99
with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (2) Cleaning up request packet ID
100 with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (3) Cleaning up request packet ID
101 with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (4) Cleaning up request packet ID
102 with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (5) Cleaning up request packet ID
103 with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (6) Cleaning up request packet ID
104 with timestamp +15
Fri Feb 10 14:29:39 2017 : Debug: (7) Cleaning up request packet ID
105 with timestamp +15
Fri Feb 10 14:29:39 2017 : Info: Ready to process requests

2017-02-09 16:16 GMT+01:00 Alan DeKok <aland@deployingradius.com>:
...
On Feb 9, 2017, at 10:09 AM, macservo via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
...
I´ve tried, but had some problems with the openssl dependencies.
The packaged versions of openssl are again pretty old and insecure.
You just read the debug output with the message about OpenSSL, and do what it says...
...
With newwer versions I´ve had problems when compiling freeradius.
Is there a more detailed version of
http://wiki.freeradius.org/building/RHEL-and-Centos
including how to "integrate" openssl?
You don't "integrate" OpenSSL.  You just build the server, and configure it.
Alan DeKok.