- Freeradius-Users - lists.freeradius.org

rlm_acct_unique missing in current version of Freeradius
by Mike Ely 22 Sep '16

22 Sep '16

At least, the Centos7 package is. I'm trying to port an install over from a Centos5 box and see acct_unique all over the configs, with a corresponding log error: Failed to link to module 'rlm_acct_unique': rlm_acct_unique.so: cannot open shared object file: No such file or directory RPM tells me that rlm_acct_unique.so came with the freeradius2 package on Centos5. So I guess my question is: has this module been deprecated/removed, or is it just missing from the vendor package for some reason? Thanks, Mike

2 2

More OpenSSL badness
by Alan DeKok 22 Sep '16

22 Sep '16

Yet another list of vulnerabilities has been released for OpenSSL. The big one is this: > A malicious client can send an excessively large OCSP Status Request extension. > If that client continually requests renegotiation, sending a large OCSP Status > Request extension each time, then there will be unbounded memory growth on the > server. This will eventually lead to a Denial Of Service attack through memory > exhaustion. Servers with a default configuration are vulnerable even if they do > not support OCSP. https://www.openssl.org/news/secadv/20160922.txt <sigh> Time for everyone to upgrade OpenSSL. Again. Alan DeKok.

1 0

Re: return statement failure
by John Kristoff 22 Sep '16

22 Sep '16

On Thu, 22 Sep 2016 14:53:27 +0000 Alan DeKok <aland(a)deployingradius.com> wrote: > Upgrade to a recent version of the server. Fair enough thanks, I'll advocate for using a recent stable tarball instead of a packaged version. > Features which are undocumented are ones which probably don't work. Hah, apparently. Legacy installs are confusing, especially when they did things they shouldn't have done. There is another place in the config that has this and doesn't result in any noticeable errors: authorized { eap { ok = return } *shrug* Time to go through the config and validate everything else that might be a little wonky. Thanks for your help, John

2 1

Re: return statement failure
by John Kristoff 22 Sep '16

22 Sep '16

On Thu, 22 Sep 2016 14:23:36 +0000 Alan DeKok <aland(a)deployingradius.com> wrote: > There's a "return" statement. > > if (ok) { > return > } Thanks Alan, but I'm still a little confused. If I have this: post-auth { if (ok) { return } That results in this: # Loading post-auth {...} /etc/raddb/sites-enabled/default[...]: Failed to find "return" in the "modules" section. /etc/raddb/sites-enabled/default[...]: Failed to parse "return" entry. /etc/raddb/sites-enabled/default[...]: Errors parsing post-auth section. If I replace the return with a noop, no errors. What am I missing now? John

2 1

return statement failure
by John Kristoff 22 Sep '16

22 Sep '16

Hello freeradius-users@, Using a packaged version 3.0.4 on a RedHat box I have in a sites-enabled/default config something that looks like this: post-auth { if (foo == barr { # do something ok = return } which results in this output with -X: # Loading post-auth {...} /etc/raddb/sites-enabled/default[...] Invalid return code assigment inside of a if section /etc/raddb/sites-enabled/default[...]: Errors parsing post-auth section. If I change 'ok = return' to just return this is the result: # Loading post-auth {...} /etc/raddb/sites-enabled/default[...]: Failed to find "return" in the "modules" section. /etc/raddb/sites-enabled/default[...]: Failed to parse "return" entry. /etc/raddb/sites-enabled/default[...]: Errors parsing post-auth section. If I remove the line with the 'return' in it, radiusd starts up just fine. I must be missing something obvious? This is adapted from a prior installation with 2.x, which apparently used to work. I'm a bit new to using FreeRADIUS and hopefully only a gentle whack with the clue bat is needed. Thanks for the clue in advance. John

3 3

Substrings with unlang
by Mikhail Sutormin 22 Sep '16

22 Sep '16

Greetings, We are running a VM with FR3 in Azure which authenticates users with their O365 credentials against Azure ADDS. The problem is a legacy 20 characters limitation of SamAccountName attribute. I strip "@domain.com" part off O365 username before passing it to ntlm_auth but some users have very long names so "sampleverylongusername" is truncated to "sampleverylonguserna" in DC. How do I right a simple check to truncate it in FR? I'm not skilled in regular expressions. So I've tried if (Stripped-User-Name =~ /(.{0,19})$/) { update request { Stripped-User-Name := "%{1}" } } but that cuts off first 20 characters and leaves the rest.

2 1

freeradius 3 ntln_auth
by Anderson Gomes 21 Sep '16

21 Sep '16

Hello, I have implemented in my centos7 freeradius 3 so far succeeded, authenticate users through Active Directory using ntlm_auth however I'm having trouble implementing rules at the level of user groups to determine which user can authenticate each SSID i tryed implement what it says on the link bellow, but I did not succeed. https://lists.freeradius.org/pipermail/freeradius-users/2014-August/073474.… if (NAS-Port-Type == Wireless-802.11) { # If User-Name doesn't contain our domain then add it. # It's needed for the Group check to use the correct # username. if (User-Name !~ /DOMAIN\\\\/i) { update request { User-Name := "DOMAIN\\\\%{User-Name}" } } if (Called-Station-Id =~ /.*:SSID-A/i) { # Can't do 'if (Group != "xxxxx")' because != # operator doesn't work for group checking. Careful # with the number of backslashes. if (!(Group == "DOMAIN\\\\group A") ) { update reply { Reply-Message = "User not allowed to join this wireless network" } reject } } elsif (Called-Station-Id =~ /.*:SSID-B/i) { if (!(Group == "DOMAIN\\\\group B") ) { update reply { Reply-Message = "User not allowed to join this wireless network" } reject } } }

2 1

authenticate Cisco devices against AD via Freeradius
by aquilinux 21 Sep '16

21 Sep '16

Hi all, i currently use my radius server (3.0.11) to do things such EAP-TTLS, MSCHAPv2, CHAP in order to authenticate different users on devices/machines/etc... I managed to configure a virtual router for doing PAP against local USERS (in users file) following a guide about IOS+Freeradius. Works perfectly. What i'd like to do now is to authenticate users from the Cisco IOS device against AD (via ldap, mschap or whatever). The device i'm using only support PAP. The radius server is joined to the AD domain, getent passwd retrives all the AD users. Is it possible? (i know, i have a lot of imagination :-)) thanks -- "Madness, like small fish, runs in hosts, in vast numbers of instances." Nessuno mi pettina bene come il vento.

2 3

Help with EAP TLS authentication
by Peter Truman 21 Sep '16

21 Sep '16

Hi there Trying to diagnose if I have a router OpenSSL issue, or a config issue (more likely). I've generated a self signed CA which seems to be working, but my new Freeradius 3 (3.0.11) "default" compile doesn't seem to like something.... Here is my radiusd -Xx dump: Tue Sep 20 18:36:13 2016 : Debug: Server was built with: Tue Sep 20 18:36:13 2016 : Debug: accounting : yes Tue Sep 20 18:36:13 2016 : Debug: authentication : yes Tue Sep 20 18:36:13 2016 : Debug: ascend-binary-attributes : yes Tue Sep 20 18:36:13 2016 : Debug: coa : yes Tue Sep 20 18:36:13 2016 : Debug: control-socket : yes Tue Sep 20 18:36:13 2016 : Debug: detail : yes Tue Sep 20 18:36:13 2016 : Debug: dhcp : yes Tue Sep 20 18:36:13 2016 : Debug: dynamic-clients : yes Tue Sep 20 18:36:13 2016 : Debug: osfc2 : no Tue Sep 20 18:36:13 2016 : Debug: proxy : yes Tue Sep 20 18:36:13 2016 : Debug: regex-pcre : no Tue Sep 20 18:36:13 2016 : Debug: regex-posix : yes Tue Sep 20 18:36:13 2016 : Debug: regex-posix-extended : yes Tue Sep 20 18:36:13 2016 : Debug: session-management : yes Tue Sep 20 18:36:13 2016 : Debug: stats : yes Tue Sep 20 18:36:13 2016 : Debug: tcp : yes Tue Sep 20 18:36:13 2016 : Debug: threads : yes Tue Sep 20 18:36:13 2016 : Debug: tls : yes Tue Sep 20 18:36:13 2016 : Debug: unlang : yes Tue Sep 20 18:36:13 2016 : Debug: vmps : yes Tue Sep 20 18:36:13 2016 : Debug: developer : no Tue Sep 20 18:36:13 2016 : Debug: Server core libs: Tue Sep 20 18:36:13 2016 : Debug: freeradius-server : 3.0.11 Tue Sep 20 18:36:13 2016 : Debug: talloc : 2.0.* Tue Sep 20 18:36:13 2016 : Debug: ssl : 1.0.1e release Tue Sep 20 18:36:13 2016 : Debug: Endianness: Tue Sep 20 18:36:13 2016 : Debug: little Tue Sep 20 18:36:13 2016 : Debug: Compilation flags: Tue Sep 20 18:36:13 2016 : Debug: cppflags : Tue Sep 20 18:36:13 2016 : Debug: cflags : -I/usr/src/freeradius-3/freeradius-server-3.0.11 -I/usr/src/freeradius-3/freeradius-server-3.0.11/src -include /usr/src/freeradius-3/freeradius-server-3.0.11/src/freeradius-devel/autoconf.h -include /usr/src/freeradius-3/freeradius-server-3.0.11/src/freeradius-devel/build.h -include /usr/src/freeradius-3/freeradius-server-3.0.11/src/freeradius-devel/features.h -include /usr/src/freeradius-3/freeradius-server-3.0.11/src/freeradius-devel/radpaths.h -fno-strict-aliasing -g -O2 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -DNDEBUG -DIS_MODULE=1 Tue Sep 20 18:36:13 2016 : Debug: ldflags : Tue Sep 20 18:36:13 2016 : Debug: libs : -lcrypto -lssl -ltalloc -lnsl -lresolv -ldl -lpthread Tue Sep 20 18:36:13 2016 : Debug: Tue Sep 20 18:36:13 2016 : Info: Copyright (C) 1999-2016 The FreeRADIUS server project and contributors Tue Sep 20 18:36:13 2016 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Tue Sep 20 18:36:13 2016 : Info: PARTICULAR PURPOSE Tue Sep 20 18:36:13 2016 : Info: You may redistribute copies of FreeRADIUS under the terms of the Tue Sep 20 18:36:13 2016 : Info: GNU General Public License Tue Sep 20 18:36:13 2016 : Info: For more information about these matters, see the file named COPYRIGHT Tue Sep 20 18:36:13 2016 : Info: Starting - reading configuration files ... Tue Sep 20 18:36:13 2016 : Debug: including dictionary file /usr/local/share/freeradius/dictionary Tue Sep 20 18:36:13 2016 : Debug: including dictionary file /usr/local/share/freeradius/dictionary.dhcp Tue Sep 20 18:36:13 2016 : Debug: including dictionary file /usr/local/share/freeradius/dictionary.vqp Tue Sep 20 18:36:13 2016 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/clients.conf Tue Sep 20 18:36:13 2016 : Debug: including files in directory /usr/local/etc/raddb/mods-enabled/ Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/linelog Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/soh Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/utf8 Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/preprocess Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/dynamic_clients Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/echo Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/mschap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/digest Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/pap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/replicate Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/exec Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/passwd Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/expr Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/files Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/unpack Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/radutmp Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/expiration Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/detail Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/unix Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/logintime Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/eap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/chap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/dhcp Tue Sep 20 18:36:13 2016 : Debug: including files in directory /usr/local/etc/raddb/policy.d/ Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/accounting Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/debug Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/control Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/canonicalization Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/filter Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/cui Tue Sep 20 18:36:13 2016 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Tue Sep 20 18:36:13 2016 : Debug: OPTIMIZING (no == yes) --> FALSE Tue Sep 20 18:36:13 2016 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Tue Sep 20 18:36:13 2016 : Debug: OPTIMIZING (no == yes) --> FALSE Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/operator-name Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/abfab-tr Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/eap Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/policy.d/dhcp Tue Sep 20 18:36:13 2016 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/ Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:13 2016 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel Tue Sep 20 18:36:13 2016 : Debug: main { Tue Sep 20 18:36:13 2016 : Debug: security { Tue Sep 20 18:36:13 2016 : Debug: allow_core_dumps = no Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[462]: The item 'max_attributes' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[480]: The item 'reject_delay' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[500]: The item 'status_server' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[510]: The item 'allow_vulnerable_openssl' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: name = "radiusd" Tue Sep 20 18:36:13 2016 : Debug: prefix = "/usr/local" Tue Sep 20 18:36:13 2016 : Debug: localstatedir = "/usr/local/var" Tue Sep 20 18:36:13 2016 : Debug: logdir = "/usr/local/var/log/radius" Tue Sep 20 18:36:13 2016 : Debug: run_dir = "/usr/local/var/run/radiusd" Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[372]: The item 'checkrad' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[529]: The item 'proxy_requests' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: main { Tue Sep 20 18:36:13 2016 : Debug: name = "radiusd" Tue Sep 20 18:36:13 2016 : Debug: prefix = "/usr/local" Tue Sep 20 18:36:13 2016 : Debug: localstatedir = "/usr/local/var" Tue Sep 20 18:36:13 2016 : Debug: sbindir = "/usr/local/sbin" Tue Sep 20 18:36:13 2016 : Debug: logdir = "/usr/local/var/log/radius" Tue Sep 20 18:36:13 2016 : Debug: run_dir = "/usr/local/var/run/radiusd" Tue Sep 20 18:36:13 2016 : Debug: libdir = "/usr/local/lib" Tue Sep 20 18:36:13 2016 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Tue Sep 20 18:36:13 2016 : Debug: hostname_lookups = no Tue Sep 20 18:36:13 2016 : Debug: max_request_time = 30 Tue Sep 20 18:36:13 2016 : Debug: cleanup_delay = 5 Tue Sep 20 18:36:13 2016 : Debug: max_requests = 16384 Tue Sep 20 18:36:13 2016 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Tue Sep 20 18:36:13 2016 : Debug: checkrad = "/usr/local/sbin/checkrad" Tue Sep 20 18:36:13 2016 : Debug: debug_level = 0 Tue Sep 20 18:36:13 2016 : Debug: proxy_requests = no Tue Sep 20 18:36:13 2016 : Debug: log { Tue Sep 20 18:36:13 2016 : Debug: stripped_names = no Tue Sep 20 18:36:13 2016 : Debug: auth = yes Tue Sep 20 18:36:13 2016 : Debug: auth_badpass = no Tue Sep 20 18:36:13 2016 : Debug: auth_goodpass = no Tue Sep 20 18:36:13 2016 : Debug: colourise = yes Tue Sep 20 18:36:13 2016 : Debug: msg_denied = "You are already logged in - access denied" Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[331]: The item 'syslog_facility' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: resources { Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: security { Tue Sep 20 18:36:13 2016 : Debug: max_attributes = 200 Tue Sep 20 18:36:13 2016 : Debug: reject_delay = 1.000000 Tue Sep 20 18:36:13 2016 : Debug: status_server = yes Tue Sep 20 18:36:13 2016 : Debug: allow_vulnerable_openssl = "CVE-2014-0160" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Warning: /usr/local/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue Sep 20 18:36:13 2016 : Debug: radiusd: #### Loading Clients #### Tue Sep 20 18:36:13 2016 : Debug: client localhost { Tue Sep 20 18:36:13 2016 : Debug: ipaddr = 127.0.0.1 Tue Sep 20 18:36:13 2016 : Debug: require_message_authenticator = no Tue Sep 20 18:36:13 2016 : Debug: secret = "testing123" Tue Sep 20 18:36:13 2016 : Debug: nas_type = "other" Tue Sep 20 18:36:13 2016 : Debug: proto = "*" Tue Sep 20 18:36:13 2016 : Debug: limit { Tue Sep 20 18:36:13 2016 : Debug: max_connections = 16 Tue Sep 20 18:36:13 2016 : Debug: lifetime = 0 Tue Sep 20 18:36:13 2016 : Debug: idle_timeout = 30 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Tue Sep 20 18:36:13 2016 : Debug: client localhost_ipv6 { Tue Sep 20 18:36:13 2016 : Debug: ipv6addr = ::1 Tue Sep 20 18:36:13 2016 : Debug: require_message_authenticator = no Tue Sep 20 18:36:13 2016 : Debug: secret = "testing123" Tue Sep 20 18:36:13 2016 : Debug: limit { Tue Sep 20 18:36:13 2016 : Debug: max_connections = 16 Tue Sep 20 18:36:13 2016 : Debug: lifetime = 0 Tue Sep 20 18:36:13 2016 : Debug: idle_timeout = 30 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Adding client ::1/128 (::1) to prefix tree 128 Tue Sep 20 18:36:13 2016 : Debug: client router-1 { Tue Sep 20 18:36:13 2016 : Debug: ipaddr = 192.168.1.1 Tue Sep 20 18:36:13 2016 : Debug: require_message_authenticator = no Tue Sep 20 18:36:13 2016 : Debug: secret = "<REDACTED>" Tue Sep 20 18:36:13 2016 : Debug: limit { Tue Sep 20 18:36:13 2016 : Debug: max_connections = 16 Tue Sep 20 18:36:13 2016 : Debug: lifetime = 0 Tue Sep 20 18:36:13 2016 : Debug: idle_timeout = 30 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Adding client 192.168.1.1/32 (192.168.1.1) to prefix tree 32 Tue Sep 20 18:36:13 2016 : Info: Debugger not attached Tue Sep 20 18:36:13 2016 : Debug: # Creating Auth-Type = eap Tue Sep 20 18:36:13 2016 : Debug: # Creating Auth-Type = PAP Tue Sep 20 18:36:13 2016 : Debug: # Creating Auth-Type = CHAP Tue Sep 20 18:36:13 2016 : Debug: # Creating Auth-Type = MS-CHAP Tue Sep 20 18:36:13 2016 : Debug: radiusd: #### Instantiating modules #### Tue Sep 20 18:36:13 2016 : Debug: modules { Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_radutmp with path: /usr/local/lib/rlm_radutmp.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_radutmp, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_radutmp Tue Sep 20 18:36:13 2016 : Debug: # Loading module "sradutmp" from file /usr/local/etc/raddb/mods-enabled/sradutmp Tue Sep 20 18:36:13 2016 : Debug: radutmp sradutmp { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/sradutmp" Tue Sep 20 18:36:13 2016 : Debug: username = "%{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: case_sensitive = yes Tue Sep 20 18:36:13 2016 : Debug: check_with_nas = yes Tue Sep 20 18:36:13 2016 : Debug: permissions = 420 Tue Sep 20 18:36:13 2016 : Debug: caller_id = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_linelog with path: /usr/local/lib/rlm_linelog.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_linelog, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_linelog Tue Sep 20 18:36:13 2016 : Debug: # Loading module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog Tue Sep 20 18:36:13 2016 : Debug: linelog { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/linelog" Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: syslog_severity = "info" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: format = "This is a log message for %{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog Tue Sep 20 18:36:13 2016 : Debug: linelog log_accounting { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/linelog-accounting" Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: syslog_severity = "info" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: format = "" Tue Sep 20 18:36:13 2016 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_detail with path: /usr/local/lib/rlm_detail.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_detail, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_detail Tue Sep 20 18:36:13 2016 : Debug: # Loading module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: detail auth_log { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Tue Sep 20 18:36:13 2016 : Debug: header = "%t" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: locking = no Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: log_packet_header = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: detail reply_log { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Tue Sep 20 18:36:13 2016 : Debug: header = "%t" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: locking = no Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: log_packet_header = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: detail pre_proxy_log { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Tue Sep 20 18:36:13 2016 : Debug: header = "%t" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: locking = no Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: log_packet_header = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: detail post_proxy_log { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Tue Sep 20 18:36:13 2016 : Debug: header = "%t" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: locking = no Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: log_packet_header = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_soh with path: /usr/local/lib/rlm_soh.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_soh, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_soh Tue Sep 20 18:36:13 2016 : Debug: # Loading module "soh" from file /usr/local/etc/raddb/mods-enabled/soh Tue Sep 20 18:36:13 2016 : Debug: soh { Tue Sep 20 18:36:13 2016 : Debug: dhcp = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_utf8 with path: /usr/local/lib/rlm_utf8.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_utf8, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_utf8 Tue Sep 20 18:36:13 2016 : Debug: # Loading module "utf8" from file /usr/local/etc/raddb/mods-enabled/utf8 Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_cache with path: /usr/local/lib/rlm_cache.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_cache, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_cache Tue Sep 20 18:36:13 2016 : Debug: # Loading module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap Tue Sep 20 18:36:13 2016 : Debug: cache cache_eap { Tue Sep 20 18:36:13 2016 : Debug: driver = "rlm_cache_rbtree" Tue Sep 20 18:36:13 2016 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" Tue Sep 20 18:36:13 2016 : Debug: ttl = 15 Tue Sep 20 18:36:13 2016 : Debug: max_entries = 0 Tue Sep 20 18:36:13 2016 : Debug: epoch = 0 Tue Sep 20 18:36:13 2016 : Debug: add_stats = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_preprocess with path: /usr/local/lib/rlm_preprocess.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_preprocess, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_preprocess Tue Sep 20 18:36:13 2016 : Debug: # Loading module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess Tue Sep 20 18:36:13 2016 : Debug: preprocess { Tue Sep 20 18:36:13 2016 : Debug: huntgroups = "/usr/local/etc/raddb/mods-config/preprocess/huntgroups" Tue Sep 20 18:36:13 2016 : Debug: hints = "/usr/local/etc/raddb/mods-config/preprocess/hints" Tue Sep 20 18:36:13 2016 : Debug: with_ascend_hack = no Tue Sep 20 18:36:13 2016 : Debug: ascend_channels_per_line = 23 Tue Sep 20 18:36:13 2016 : Debug: with_ntdomain_hack = no Tue Sep 20 18:36:13 2016 : Debug: with_specialix_jetstream_hack = no Tue Sep 20 18:36:13 2016 : Debug: with_cisco_vsa_hack = no Tue Sep 20 18:36:13 2016 : Debug: with_alvarion_vsa_hack = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_realm with path: /usr/local/lib/rlm_realm.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_realm, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_realm Tue Sep 20 18:36:13 2016 : Debug: # Loading module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: realm IPASS { Tue Sep 20 18:36:13 2016 : Debug: format = "prefix" Tue Sep 20 18:36:13 2016 : Debug: delimiter = "/" Tue Sep 20 18:36:13 2016 : Debug: ignore_default = no Tue Sep 20 18:36:13 2016 : Debug: ignore_null = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: realm suffix { Tue Sep 20 18:36:13 2016 : Debug: format = "suffix" Tue Sep 20 18:36:13 2016 : Debug: delimiter = "@" Tue Sep 20 18:36:13 2016 : Debug: ignore_default = no Tue Sep 20 18:36:13 2016 : Debug: ignore_null = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: realm realmpercent { Tue Sep 20 18:36:13 2016 : Debug: format = "suffix" Tue Sep 20 18:36:13 2016 : Debug: delimiter = "%" Tue Sep 20 18:36:13 2016 : Debug: ignore_default = no Tue Sep 20 18:36:13 2016 : Debug: ignore_null = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: realm ntdomain { Tue Sep 20 18:36:13 2016 : Debug: format = "prefix" Tue Sep 20 18:36:13 2016 : Debug: delimiter = "\\" Tue Sep 20 18:36:13 2016 : Debug: ignore_default = no Tue Sep 20 18:36:13 2016 : Debug: ignore_null = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_dynamic_clients with path: /usr/local/lib/rlm_dynamic_clients.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_dynamic_clients, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_dynamic_clients Tue Sep 20 18:36:13 2016 : Debug: # Loading module "dynamic_clients" from file /usr/local/etc/raddb/mods-enabled/dynamic_clients Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_exec with path: /usr/local/lib/rlm_exec.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_exec, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_exec Tue Sep 20 18:36:13 2016 : Debug: # Loading module "echo" from file /usr/local/etc/raddb/mods-enabled/echo Tue Sep 20 18:36:13 2016 : Debug: exec echo { Tue Sep 20 18:36:13 2016 : Debug: wait = yes Tue Sep 20 18:36:13 2016 : Debug: program = "/bin/echo %{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: input_pairs = "request" Tue Sep 20 18:36:13 2016 : Debug: output_pairs = "reply" Tue Sep 20 18:36:13 2016 : Debug: shell_escape = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_mschap with path: /usr/local/lib/rlm_mschap.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_mschap, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_mschap Tue Sep 20 18:36:13 2016 : Debug: # Loading module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap Tue Sep 20 18:36:13 2016 : Debug: mschap { Tue Sep 20 18:36:13 2016 : Debug: use_mppe = yes Tue Sep 20 18:36:13 2016 : Debug: require_encryption = no Tue Sep 20 18:36:13 2016 : Debug: require_strong = no Tue Sep 20 18:36:13 2016 : Debug: with_ntdomain_hack = yes Tue Sep 20 18:36:13 2016 : Debug: passchange { Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: allow_retry = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_digest with path: /usr/local/lib/rlm_digest.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_digest, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_digest Tue Sep 20 18:36:13 2016 : Debug: # Loading module "digest" from file /usr/local/etc/raddb/mods-enabled/digest Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_pap with path: /usr/local/lib/rlm_pap.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_pap, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_pap Tue Sep 20 18:36:13 2016 : Debug: # Loading module "pap" from file /usr/local/etc/raddb/mods-enabled/pap Tue Sep 20 18:36:13 2016 : Debug: pap { Tue Sep 20 18:36:13 2016 : Debug: normalise = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_replicate with path: /usr/local/lib/rlm_replicate.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_replicate, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_replicate Tue Sep 20 18:36:13 2016 : Debug: # Loading module "replicate" from file /usr/local/etc/raddb/mods-enabled/replicate Tue Sep 20 18:36:13 2016 : Debug: # Loading module "exec" from file /usr/local/etc/raddb/mods-enabled/exec Tue Sep 20 18:36:13 2016 : Debug: exec { Tue Sep 20 18:36:13 2016 : Debug: wait = no Tue Sep 20 18:36:13 2016 : Debug: input_pairs = "request" Tue Sep 20 18:36:13 2016 : Debug: shell_escape = yes Tue Sep 20 18:36:13 2016 : Debug: timeout = 10 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_passwd with path: /usr/local/lib/rlm_passwd.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_passwd, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_passwd Tue Sep 20 18:36:13 2016 : Debug: # Loading module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd Tue Sep 20 18:36:13 2016 : Debug: passwd etc_passwd { Tue Sep 20 18:36:13 2016 : Debug: filename = "/etc/passwd" Tue Sep 20 18:36:13 2016 : Debug: format = "*User-Name:Crypt-Password:" Tue Sep 20 18:36:13 2016 : Debug: delimiter = ":" Tue Sep 20 18:36:13 2016 : Debug: ignore_nislike = no Tue Sep 20 18:36:13 2016 : Debug: ignore_empty = yes Tue Sep 20 18:36:13 2016 : Debug: allow_multiple_keys = no Tue Sep 20 18:36:13 2016 : Debug: hash_size = 100 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_expr with path: /usr/local/lib/rlm_expr.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_expr, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_expr Tue Sep 20 18:36:13 2016 : Debug: # Loading module "expr" from file /usr/local/etc/raddb/mods-enabled/expr Tue Sep 20 18:36:13 2016 : Debug: expr { Tue Sep 20 18:36:13 2016 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_files with path: /usr/local/lib/rlm_files.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_files, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_files Tue Sep 20 18:36:13 2016 : Debug: # Loading module "files" from file /usr/local/etc/raddb/mods-enabled/files Tue Sep 20 18:36:13 2016 : Debug: files { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/files/authorize" Tue Sep 20 18:36:13 2016 : Debug: acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting" Tue Sep 20 18:36:13 2016 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_unpack with path: /usr/local/lib/rlm_unpack.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_unpack, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_unpack Tue Sep 20 18:36:13 2016 : Debug: # Loading module "unpack" from file /usr/local/etc/raddb/mods-enabled/unpack Tue Sep 20 18:36:13 2016 : Debug: # Loading module "radutmp" from file /usr/local/etc/raddb/mods-enabled/radutmp Tue Sep 20 18:36:13 2016 : Debug: radutmp { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radutmp" Tue Sep 20 18:36:13 2016 : Debug: username = "%{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: case_sensitive = yes Tue Sep 20 18:36:13 2016 : Debug: check_with_nas = yes Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: caller_id = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_expiration with path: /usr/local/lib/rlm_expiration.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_expiration, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_expiration Tue Sep 20 18:36:13 2016 : Debug: # Loading module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_always with path: /usr/local/lib/rlm_always.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_always, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_always Tue Sep 20 18:36:13 2016 : Debug: # Loading module "reject" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always reject { Tue Sep 20 18:36:13 2016 : Debug: rcode = "reject" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "fail" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always fail { Tue Sep 20 18:36:13 2016 : Debug: rcode = "fail" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "ok" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always ok { Tue Sep 20 18:36:13 2016 : Debug: rcode = "ok" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "handled" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always handled { Tue Sep 20 18:36:13 2016 : Debug: rcode = "handled" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "invalid" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always invalid { Tue Sep 20 18:36:13 2016 : Debug: rcode = "invalid" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "userlock" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always userlock { Tue Sep 20 18:36:13 2016 : Debug: rcode = "userlock" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "notfound" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always notfound { Tue Sep 20 18:36:13 2016 : Debug: rcode = "notfound" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "noop" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always noop { Tue Sep 20 18:36:13 2016 : Debug: rcode = "noop" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "updated" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: always updated { Tue Sep 20 18:36:13 2016 : Debug: rcode = "updated" Tue Sep 20 18:36:13 2016 : Debug: simulcount = 0 Tue Sep 20 18:36:13 2016 : Debug: mpp = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "detail" from file /usr/local/etc/raddb/mods-enabled/detail Tue Sep 20 18:36:13 2016 : Debug: detail { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Tue Sep 20 18:36:13 2016 : Debug: header = "%t" Tue Sep 20 18:36:13 2016 : Debug: permissions = 384 Tue Sep 20 18:36:13 2016 : Debug: locking = no Tue Sep 20 18:36:13 2016 : Debug: escape_filenames = no Tue Sep 20 18:36:13 2016 : Debug: log_packet_header = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_attr_filter with path: /usr/local/lib/rlm_attr_filter.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_attr_filter, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_attr_filter Tue Sep 20 18:36:13 2016 : Debug: # Loading module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: attr_filter attr_filter.post-proxy { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy" Tue Sep 20 18:36:13 2016 : Debug: key = "%{Realm}" Tue Sep 20 18:36:13 2016 : Debug: relaxed = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: attr_filter attr_filter.pre-proxy { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy" Tue Sep 20 18:36:13 2016 : Debug: key = "%{Realm}" Tue Sep 20 18:36:13 2016 : Debug: relaxed = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: attr_filter attr_filter.access_reject { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject" Tue Sep 20 18:36:13 2016 : Debug: key = "%{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: relaxed = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: attr_filter attr_filter.access_challenge { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge" Tue Sep 20 18:36:13 2016 : Debug: key = "%{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: relaxed = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: attr_filter attr_filter.accounting_response { Tue Sep 20 18:36:13 2016 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response" Tue Sep 20 18:36:13 2016 : Debug: key = "%{User-Name}" Tue Sep 20 18:36:13 2016 : Debug: relaxed = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Loading module "ntlm_auth" from file /usr/local/etc/raddb/mods-enabled/ntlm_auth Tue Sep 20 18:36:13 2016 : Debug: exec ntlm_auth { Tue Sep 20 18:36:13 2016 : Debug: wait = yes Tue Sep 20 18:36:13 2016 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Tue Sep 20 18:36:13 2016 : Debug: shell_escape = yes Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_unix with path: /usr/local/lib/rlm_unix.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_unix, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_unix Tue Sep 20 18:36:13 2016 : Debug: # Loading module "unix" from file /usr/local/etc/raddb/mods-enabled/unix Tue Sep 20 18:36:13 2016 : Debug: unix { Tue Sep 20 18:36:13 2016 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Creating attribute Unix-Group Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_logintime with path: /usr/local/lib/rlm_logintime.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_logintime, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_logintime Tue Sep 20 18:36:13 2016 : Debug: # Loading module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime Tue Sep 20 18:36:13 2016 : Debug: logintime { Tue Sep 20 18:36:13 2016 : Debug: minimum_timeout = 60 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_eap with path: /usr/local/lib/rlm_eap.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_eap, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_eap Tue Sep 20 18:36:13 2016 : Debug: # Loading module "eap" from file /usr/local/etc/raddb/mods-enabled/eap Tue Sep 20 18:36:13 2016 : Debug: eap { Tue Sep 20 18:36:13 2016 : Debug: default_eap_type = "tls" Tue Sep 20 18:36:13 2016 : Debug: timer_expire = 60 Tue Sep 20 18:36:13 2016 : Debug: ignore_unknown_eap_types = no Tue Sep 20 18:36:13 2016 : Debug: cisco_accounting_username_bug = no Tue Sep 20 18:36:13 2016 : Debug: max_sessions = 16384 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_chap with path: /usr/local/lib/rlm_chap.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_chap, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_chap Tue Sep 20 18:36:13 2016 : Debug: # Loading module "chap" from file /usr/local/etc/raddb/mods-enabled/chap Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_dhcp with path: /usr/local/lib/rlm_dhcp.so Tue Sep 20 18:36:13 2016 : Debug: Loaded rlm_dhcp, checking if it's valid Tue Sep 20 18:36:13 2016 : Debug: # Loaded module rlm_dhcp Tue Sep 20 18:36:13 2016 : Debug: # Loading module "dhcp" from file /usr/local/etc/raddb/mods-enabled/dhcp Tue Sep 20 18:36:13 2016 : Debug: Adding values for DHCP-Parameter-Request-List Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 1 DHCP-Subnet-Mask Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 2 DHCP-Time-Offset Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 3 DHCP-Router-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 4 DHCP-Time-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 5 DHCP-IEN-116-Name-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 6 DHCP-Domain-Name-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 7 DHCP-Log-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 8 DHCP-Quotes-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 9 DHCP-LPR-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 10 DHCP-Impress-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 11 DHCP-RLP-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 12 DHCP-Hostname Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 13 DHCP-Boot-File-Size Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 14 DHCP-Merit-Dump-File Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 15 DHCP-Domain-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 16 DHCP-Swap-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 17 DHCP-Root-Path Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 18 DHCP-Bootp-Extensions-Path Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 19 DHCP-IP-Forward-Enable Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 20 DHCP-Source-Route-Enable Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 21 DHCP-Policy-Filter Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 22 DHCP-Max-Datagram-Reassembly-Size Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 23 DHCP-Default-IP-TTL Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 24 DHCP-Path-MTU-Aging-Timeout Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 25 DHCP-Path-MTU-Plateau-Table Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 26 DHCP-Interface-MTU-Size Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 27 DHCP-All-Subnets-Are-Local Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 28 DHCP-Broadcast-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 29 DHCP-Perform-Mask-Discovery Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 30 DHCP-Provide-Mask-To-Others Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 31 DHCP-Perform-Router-Discovery Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 32 DHCP-Router-Solicitation-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 33 DHCP-Static-Routes Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 34 DHCP-Trailer-Encapsulation Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 35 DHCP-ARP-Cache-Timeout Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 36 DHCP-Ethernet-Encapsulation Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 37 DHCP-Default-TCP-TTL Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 38 DHCP-Keep-Alive-Interval Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 39 DHCP-Keep-Alive-Garbage Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 40 DHCP-NIS-Domain-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 41 DHCP-NIS-Servers Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 42 DHCP-NTP-Servers Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 43 DHCP-Vendor Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 44 DHCP-NETBIOS-Name-Servers Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 45 DHCP-NETBIOS-Dgm-Dist-Servers Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 46 DHCP-NETBIOS-Node-Type Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 47 DHCP-NETBIOS Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 48 DHCP-X-Window-Font-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 49 DHCP-X-Window-Display-Mgr Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 50 DHCP-Requested-IP-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 51 DHCP-IP-Address-Lease-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 52 DHCP-Overload Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 53 DHCP-Message-Type Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 54 DHCP-DHCP-Server-Identifier Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 55 DHCP-Parameter-Request-List Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 56 DHCP-DHCP-Error-Message Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 57 DHCP-DHCP-Maximum-Msg-Size Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 58 DHCP-Renewal-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 59 DHCP-Rebinding-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 60 DHCP-Vendor-Class-Identifier Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 61 DHCP-Client-Identifier Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 62 DHCP-Netware-Domain-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 63 DHCP-Netware-Sub-Options Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 64 DHCP-NIS-Client-Domain-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 65 DHCP-NIS-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 66 DHCP-TFTP-Server-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 67 DHCP-Boot-File-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 68 DHCP-Home-Agent-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 69 DHCP-SMTP-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 70 DHCP-POP3-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 71 DHCP-NNTP-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 72 DHCP-WWW-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 73 DHCP-Finger-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 74 DHCP-IRC-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 75 DHCP-StreetTalk-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 76 DHCP-STDA-Server-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 77 DHCP-User-Class Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 78 DHCP-Directory-Agent Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 79 DHCP-Service-Scope Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 80 DHCP-Rapid-Commit Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 81 DHCP-Client-FQDN Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 82 DHCP-Relay-Agent-Information Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 83 DHCP-iSNS Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 84 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 85 DHCP-NDS-Servers Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 86 DHCP-NDS-Tree-Name Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 87 DHCP-NDS-Context Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 88 DHCP-BCMS-Server-IPv4-FQDN Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 89 DHCP-BCMS-Server-IPv4-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 90 DHCP-Authentication Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 91 DHCP-Client-Last-Txn-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 92 DHCP-associated-ip Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 93 DHCP-Client-System Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 94 DHCP-Client-NDI Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 95 DHCP-LDAP Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 96 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 97 DHCP-UUID/GUID Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 98 DHCP-User-Auth Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 99 DHCP-GeoConf-Civic Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 100 DHCP-Timezone-Posix Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 101 DHCP-Timezone-Database Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 102 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 103 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 104 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 105 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 106 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 107 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 108 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 109 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 110 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 111 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 112 DHCP-Netinfo-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 113 DHCP-Netinfo-Tag Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 114 DHCP-URL Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 115 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 116 DHCP-Auto-Config Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 117 DHCP-Name-Service-Search Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 118 DHCP-Subnet-Selection-Option Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 119 DHCP-Domain-Search Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 120 DHCP-SIP-Servers-DHCP-Option Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 121 DHCP-Classless-Static-Route Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 122 DHCP-CCC Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 123 DHCP-GeoConf-Option Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 124 DHCP-V-I-Vendor-Class Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 125 DHCP-V-I-Vendor-Specific Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 126 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 127 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 128 DHCP-TFTP-Server-IP-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 129 DHCP-Call-Server-IP-address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 130 DHCP-Vendor-Discrimination-Str Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 131 DHCP-Remote-Stats-Svr-IP-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 132 DHCP-IEEE-802.1P-VLAN-ID Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 133 DHCP-IEEE-802.1Q-L2-Priority Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 134 DHCP-Diffserv-Code-Point Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 135 DHCP-HTTP-Proxy Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 136 DHCP-PANA-Agent Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 137 DHCP-LoST-Server Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 138 DHCP-CAPWAP-AC-IPv4-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 139 DHCP-MoS-IPv4-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 140 DHCP-MoS-IPv4-FQDN Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 141 DHCP-SIP-UA-Configuration-Service-Domains Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 142 DHCP-ANDSF-IPv4-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 143 DHCP-ANDSF-IPv6-Address Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 144 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 145 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 146 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 147 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 148 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 149 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 150 DHCP-TFTP-Server-IPv4-Address Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 151 DHCP-Query-Status-Code Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 152 DHCP-Query-Server-Base-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 153 DHCP-Query-Start-Time-Of-State Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 154 DHCP-Query-Start-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 155 DHCP-Query-End-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 156 DHCP-State Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 157 DHCP-Data-Source Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 158 DHCP-PCP-IPv4-Server-Address Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 159 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 160 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 161 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 162 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 163 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 164 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 165 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 166 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 167 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 168 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 169 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 170 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 171 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 172 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 173 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 174 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 175 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 176 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 177 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 178 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 179 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 180 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 181 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 182 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 183 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 184 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 185 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 186 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 187 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 188 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 189 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 190 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 191 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 192 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 193 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 194 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 195 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 196 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 197 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 198 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 199 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 200 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 201 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 202 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 203 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 204 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 205 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 206 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 207 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 208 DHCP-PXELINUX-Magic Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 209 DHCP-Packet-Format Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 210 DHCP-Path-Prefix Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 211 DHCP-Reboot-Time Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 212 DHCP-6RD Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 213 DHCP-Access-Network-Domain-Name Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 214 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 215 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 216 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 217 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 218 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 219 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 220 DHCP-Virtual-Subnet-Allocation Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 221 DHCP-Virtual-Subnet-Selection Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 222 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 223 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 224 DHCP-Site-specific-0 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 225 DHCP-Site-specific-1 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 226 DHCP-Site-specific-2 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 227 DHCP-Site-specific-3 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 228 DHCP-Site-specific-4 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 229 DHCP-Site-specific-5 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 230 DHCP-Site-specific-6 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 231 DHCP-Site-specific-7 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 232 DHCP-Site-specific-8 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 233 DHCP-Site-specific-9 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 234 DHCP-Site-specific-10 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 235 DHCP-Site-specific-11 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 236 DHCP-Site-specific-12 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 237 DHCP-Site-specific-13 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 238 DHCP-Site-specific-14 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 239 DHCP-Site-specific-15 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 240 DHCP-Site-specific-16 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 241 DHCP-Site-specific-17 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 242 DHCP-Site-specific-18 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 243 DHCP-Site-specific-19 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 244 DHCP-Site-specific-20 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 245 DHCP-Site-specific-21 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 246 DHCP-Site-specific-22 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 247 DHCP-Site-specific-23 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 248 DHCP-Site-specific-24 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 249 DHCP-Site-specific-25 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 250 DHCP-Site-specific-26 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 251 DHCP-Site-specific-27 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 252 DHCP-Site-specific-28 Tue Sep 20 18:36:13 2016 : Debug: Adding DHCP-Parameter-Request-List value 253 DHCP-Site-specific-30 Tue Sep 20 18:36:13 2016 : Debug: No DHCP RFC space attribute at 254 Tue Sep 20 18:36:13 2016 : Debug: instantiate { Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_cache_rbtree with path: /usr/local/lib/rlm_cache_rbtree.so Tue Sep 20 18:36:13 2016 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/huntgroups Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/hints Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap Tue Sep 20 18:36:13 2016 : Debug: rlm_mschap (mschap): using internal authentication Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "pap" from file /usr/local/etc/raddb/mods-enabled/pap Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd Tue Sep 20 18:36:13 2016 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "files" from file /usr/local/etc/raddb/mods-enabled/files Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/authorize Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/accounting Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/pre-proxy Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "reject" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "fail" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "ok" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "handled" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "invalid" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "userlock" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "notfound" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "noop" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "updated" from file /usr/local/etc/raddb/mods-enabled/always Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "detail" from file /usr/local/etc/raddb/mods-enabled/detail Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_reject Tue Sep 20 18:36:13 2016 : Warning: [/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Tue Sep 20 18:36:13 2016 : Warning: [/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter Tue Sep 20 18:36:13 2016 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime Tue Sep 20 18:36:13 2016 : Debug: # Instantiating module "eap" from file /usr/local/etc/raddb/mods-enabled/eap Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_eap_tls with path: /usr/local/lib/rlm_eap_tls.so Tue Sep 20 18:36:13 2016 : Debug: # Linked to sub-module rlm_eap_tls Tue Sep 20 18:36:13 2016 : Debug: tls { Tue Sep 20 18:36:13 2016 : Debug: tls = "tls-common" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: tls-config tls-common { Tue Sep 20 18:36:13 2016 : Debug: verify_depth = 0 Tue Sep 20 18:36:13 2016 : Debug: ca_path = "/usr/local/etc/raddb/certs" Tue Sep 20 18:36:13 2016 : Debug: pem_file_type = yes Tue Sep 20 18:36:13 2016 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.key" Tue Sep 20 18:36:13 2016 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.crt" Tue Sep 20 18:36:13 2016 : Debug: ca_file = "/usr/local/etc/raddb/certs/ca.pem" Tue Sep 20 18:36:13 2016 : Debug: private_key_password = "<REDACTED>" Tue Sep 20 18:36:13 2016 : Debug: random_file = "/dev/urandom" Tue Sep 20 18:36:13 2016 : Debug: fragment_size = 1024 Tue Sep 20 18:36:13 2016 : Debug: include_length = yes Tue Sep 20 18:36:13 2016 : Debug: auto_chain = yes Tue Sep 20 18:36:13 2016 : Debug: check_crl = no Tue Sep 20 18:36:13 2016 : Debug: check_all_crl = no Tue Sep 20 18:36:13 2016 : Debug: cipher_list = "HIGH" Tue Sep 20 18:36:13 2016 : Debug: ecdh_curve = "prime256v1" Tue Sep 20 18:36:13 2016 : Debug: cache { Tue Sep 20 18:36:13 2016 : Debug: enable = yes Tue Sep 20 18:36:13 2016 : Debug: lifetime = 24 Tue Sep 20 18:36:13 2016 : Debug: max_entries = 255 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: verify { Tue Sep 20 18:36:13 2016 : Debug: skip_if_ocsp_ok = no Tue Sep 20 18:36:13 2016 : Debug: tmpdir = "/tmp/radiusd" Tue Sep 20 18:36:13 2016 : Debug: client = "/usr/bin/openssl verify -CApath /usr/local/etc/raddb/certs %{TLS-Client-Cert-Filename}" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: ocsp { Tue Sep 20 18:36:13 2016 : Debug: enable = no Tue Sep 20 18:36:13 2016 : Debug: override_cert_url = yes Tue Sep 20 18:36:13 2016 : Debug: url = "http://127.0.0.1/ocsp/" Tue Sep 20 18:36:13 2016 : Debug: use_nonce = yes Tue Sep 20 18:36:13 2016 : Debug: timeout = 0 Tue Sep 20 18:36:13 2016 : Debug: softfail = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading rlm_eap_ttls with path: /usr/local/lib/rlm_eap_ttls.so Tue Sep 20 18:36:13 2016 : Debug: # Linked to sub-module rlm_eap_ttls Tue Sep 20 18:36:13 2016 : Debug: ttls { Tue Sep 20 18:36:13 2016 : Debug: tls = "tls-common" Tue Sep 20 18:36:13 2016 : Debug: default_eap_type = "md5" Tue Sep 20 18:36:13 2016 : Debug: copy_request_to_tunnel = no Tue Sep 20 18:36:13 2016 : Debug: use_tunneled_reply = no Tue Sep 20 18:36:13 2016 : Debug: virtual_server = "inner-tunnel" Tue Sep 20 18:36:13 2016 : Debug: include_length = no Tue Sep 20 18:36:13 2016 : Debug: require_client_cert = no Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: tls: Using cached TLS configuration from previous invocation Tue Sep 20 18:36:13 2016 : Debug: } # modules Tue Sep 20 18:36:13 2016 : Debug: radiusd: #### Loading Virtual Servers #### Tue Sep 20 18:36:13 2016 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Tue Sep 20 18:36:13 2016 : Debug: } # server Tue Sep 20 18:36:13 2016 : Debug: server default { # from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:13 2016 : Debug: authenticate { Tue Sep 20 18:36:13 2016 : Debug: eap Tue Sep 20 18:36:13 2016 : Debug: } # authenticate Tue Sep 20 18:36:13 2016 : Debug: authorize { Tue Sep 20 18:36:13 2016 : Debug: preprocess Tue Sep 20 18:36:13 2016 : Debug: eap Tue Sep 20 18:36:13 2016 : Debug: } # authorize Tue Sep 20 18:36:13 2016 : Debug: preacct { Tue Sep 20 18:36:13 2016 : Debug: preprocess Tue Sep 20 18:36:13 2016 : Debug: policy acct_unique { Tue Sep 20 18:36:13 2016 : Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: else { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: suffix Tue Sep 20 18:36:13 2016 : Debug: files Tue Sep 20 18:36:13 2016 : Debug: } # preacct Tue Sep 20 18:36:13 2016 : Debug: accounting { Tue Sep 20 18:36:13 2016 : Debug: detail Tue Sep 20 18:36:13 2016 : Debug: unix Tue Sep 20 18:36:13 2016 : Debug: radutmp Tue Sep 20 18:36:13 2016 : Debug: attr_filter.accounting_response Tue Sep 20 18:36:13 2016 : Debug: } # accounting Tue Sep 20 18:36:13 2016 : Debug: session { Tue Sep 20 18:36:13 2016 : Debug: radutmp Tue Sep 20 18:36:13 2016 : Debug: } # session Tue Sep 20 18:36:13 2016 : Debug: post-auth { Tue Sep 20 18:36:13 2016 : Debug: exec Tue Sep 20 18:36:13 2016 : Debug: group { Tue Sep 20 18:36:13 2016 : Debug: attr_filter.access_reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } # post-auth Tue Sep 20 18:36:13 2016 : Debug: } # server default Tue Sep 20 18:36:13 2016 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Tue Sep 20 18:36:13 2016 : Debug: authenticate { Tue Sep 20 18:36:13 2016 : Debug: group { Tue Sep 20 18:36:13 2016 : Debug: pap Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: group { Tue Sep 20 18:36:13 2016 : Debug: chap Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: group { Tue Sep 20 18:36:13 2016 : Debug: mschap Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: eap Tue Sep 20 18:36:13 2016 : Debug: } # authenticate Tue Sep 20 18:36:13 2016 : Debug: authorize { Tue Sep 20 18:36:13 2016 : Debug: policy filter_username { Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name) { Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ / /) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ /@[^@]*@/) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ /\.\./) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ /\.$/) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: if (&User-Name =~ /(a)\./) { Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: reject Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: chap Tue Sep 20 18:36:13 2016 : Debug: mschap Tue Sep 20 18:36:13 2016 : Debug: suffix Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &control:Proxy-To-Realm := LOCAL Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: eap Tue Sep 20 18:36:13 2016 : Debug: files Tue Sep 20 18:36:13 2016 : Warning: Ignoring "sql" (see raddb/mods-available/README.rst) Tue Sep 20 18:36:13 2016 : Warning: Ignoring "ldap" (see raddb/mods-available/README.rst) Tue Sep 20 18:36:13 2016 : Debug: expiration Tue Sep 20 18:36:13 2016 : Debug: logintime Tue Sep 20 18:36:13 2016 : Debug: pap Tue Sep 20 18:36:13 2016 : Debug: } # authorize Tue Sep 20 18:36:13 2016 : Debug: session { Tue Sep 20 18:36:13 2016 : Debug: radutmp Tue Sep 20 18:36:13 2016 : Debug: } # session Tue Sep 20 18:36:13 2016 : Debug: post-auth { Tue Sep 20 18:36:13 2016 : Debug: group { Tue Sep 20 18:36:13 2016 : Debug: attr_filter.access_reject Tue Sep 20 18:36:13 2016 : Debug: update { Tue Sep 20 18:36:13 2016 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: } # post-auth Tue Sep 20 18:36:13 2016 : Debug: } # server inner-tunnel Tue Sep 20 18:36:13 2016 : Debug: Created signal pipe. Read end FD 5, write end FD 6 Tue Sep 20 18:36:13 2016 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Sep 20 18:36:13 2016 : Debug: Loading proto_auth with path: /usr/local/lib/proto_auth.so Tue Sep 20 18:36:13 2016 : Debug: Loading proto_auth failed: /usr/local/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Tue Sep 20 18:36:13 2016 : Debug: Loading library using linker search path(s) Tue Sep 20 18:36:13 2016 : Debug: Defaults : /lib:/usr/lib Tue Sep 20 18:36:13 2016 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Tue Sep 20 18:36:13 2016 : Debug: listen { Tue Sep 20 18:36:13 2016 : Debug: type = "auth" Tue Sep 20 18:36:13 2016 : Debug: ipaddr = * Tue Sep 20 18:36:13 2016 : Debug: port = 1812 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Loading proto_auth with path: /usr/local/lib/proto_auth.so Tue Sep 20 18:36:13 2016 : Debug: Loading proto_auth failed: /usr/local/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Tue Sep 20 18:36:13 2016 : Debug: Loading library using linker search path(s) Tue Sep 20 18:36:13 2016 : Debug: Defaults : /lib:/usr/lib Tue Sep 20 18:36:13 2016 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Tue Sep 20 18:36:13 2016 : Debug: listen { Tue Sep 20 18:36:13 2016 : Debug: type = "auth" Tue Sep 20 18:36:13 2016 : Debug: ipaddr = 127.0.0.1 Tue Sep 20 18:36:13 2016 : Debug: port = 18120 Tue Sep 20 18:36:13 2016 : Debug: } Tue Sep 20 18:36:13 2016 : Debug: Listening on auth address * port 1812 bound to server default Tue Sep 20 18:36:13 2016 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Tue Sep 20 18:36:13 2016 : Info: Ready to process requests Tue Sep 20 18:36:16 2016 : Debug: (0) Received Access-Request Id 0 from 192.168.1.1:12227 to 192.168.1.210:1812 length 139 Tue Sep 20 18:36:16 2016 : Debug: (0) User-Name = "pete@nexus5xp" Tue Sep 20 18:36:16 2016 : Debug: (0) NAS-IP-Address = 192.168.1.1 Tue Sep 20 18:36:16 2016 : Debug: (0) Called-Station-Id = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (0) Calling-Station-Id = "64bc0c4b27bf" Tue Sep 20 18:36:16 2016 : Debug: (0) NAS-Identifier = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (0) NAS-Port = 83 Tue Sep 20 18:36:16 2016 : Debug: (0) Framed-MTU = 1400 Tue Sep 20 18:36:16 2016 : Debug: (0) NAS-Port-Type = Wireless-802.11 Tue Sep 20 18:36:16 2016 : Debug: (0) EAP-Message = 0x020000120170657465406e65787573357870 Tue Sep 20 18:36:16 2016 : Debug: (0) Message-Authenticator = 0x451b844658c31c179b5e494fec393516 Tue Sep 20 18:36:16 2016 : Debug: (0) session-state: No State attribute Tue Sep 20 18:36:16 2016 : Debug: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (0) authorize { Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) [preprocess] = ok Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) eap: Peer sent EAP Response (code 2) ID 0 length 18 Tue Sep 20 18:36:16 2016 : Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) [eap] = ok Tue Sep 20 18:36:16 2016 : Debug: (0) } # authorize = ok Tue Sep 20 18:36:16 2016 : Debug: (0) Found Auth-Type = eap Tue Sep 20 18:36:16 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (0) authenticate { Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) eap: Peer sent packet with method EAP Identity (1) Tue Sep 20 18:36:16 2016 : Debug: (0) eap: Calling submodule eap_tls to process data Tue Sep 20 18:36:16 2016 : Debug: (0) eap_tls: Initiating new EAP-TLS session Tue Sep 20 18:36:16 2016 : Debug: (0) eap_tls: Flushing SSL sessions (of #0) Tue Sep 20 18:36:16 2016 : Debug: (0) eap_tls: Setting verify mode to require certificate from client Tue Sep 20 18:36:16 2016 : Debug: (0) eap_tls: [eaptls start] = request Tue Sep 20 18:36:16 2016 : Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 6 Tue Sep 20 18:36:16 2016 : Debug: (0) eap: EAP session adding &reply:State = 0xc0a4b23ec0a5bf93 Tue Sep 20 18:36:16 2016 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Tue Sep 20 18:36:16 2016 : Debug: (0) [eap] = handled Tue Sep 20 18:36:16 2016 : Debug: (0) } # authenticate = handled Tue Sep 20 18:36:16 2016 : Debug: (0) Using Post-Auth-Type Challenge Tue Sep 20 18:36:16 2016 : Debug: (0) Post-Auth-Type sub-section not found. Ignoring. Tue Sep 20 18:36:16 2016 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (0) session-state: Nothing to cache Tue Sep 20 18:36:16 2016 : Debug: (0) Sent Access-Challenge Id 0 from 192.168.1.210:1812 to 192.168.1.1:12227 length 0 Tue Sep 20 18:36:16 2016 : Debug: (0) EAP-Message = 0x010100060d20 Tue Sep 20 18:36:16 2016 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000 Tue Sep 20 18:36:16 2016 : Debug: (0) State = 0xc0a4b23ec0a5bf931b6e88d496e35305 Tue Sep 20 18:36:16 2016 : Debug: (0) Finished request Tue Sep 20 18:36:16 2016 : Debug: Waking up in 4.9 seconds. Tue Sep 20 18:36:16 2016 : Debug: (0) Cleaning up request packet ID 0 with timestamp +3 Tue Sep 20 18:36:16 2016 : Debug: (1) Received Access-Request Id 0 from 192.168.1.1:12227 to 192.168.1.210:1812 length 310 Tue Sep 20 18:36:16 2016 : Debug: (1) User-Name = "pete@nexus5xp" Tue Sep 20 18:36:16 2016 : Debug: (1) NAS-IP-Address = 192.168.1.1 Tue Sep 20 18:36:16 2016 : Debug: (1) Called-Station-Id = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (1) Calling-Station-Id = "64bc0c4b27bf" Tue Sep 20 18:36:16 2016 : Debug: (1) NAS-Identifier = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (1) NAS-Port = 83 Tue Sep 20 18:36:16 2016 : Debug: (1) Framed-MTU = 1400 Tue Sep 20 18:36:16 2016 : Debug: (1) State = 0xc0a4b23ec0a5bf931b6e88d496e35305 Tue Sep 20 18:36:16 2016 : Debug: (1) NAS-Port-Type = Wireless-802.11 Tue Sep 20 18:36:16 2016 : Debug: (1) EAP-Message = 0x020100ab0d0016030100a00100009c03038ef92dd289a9e47a08043ed8d17ba4aadbe9b997be545a3133beddda398a072b00003ec02cc030009fc02bc02f009ecca9cca8c00ac024c014c0280039006bc009c023c013c02700330067c007c011009d009c0035003d002f003c00050004000a01000035ff Tue Sep 20 18:36:16 2016 : Debug: (1) Message-Authenticator = 0x884979e1a62906f3099fec79b717a9e0 Tue Sep 20 18:36:16 2016 : Debug: (1) session-state: No cached attributes Tue Sep 20 18:36:16 2016 : Debug: (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (1) authorize { Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) [preprocess] = ok Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Peer sent EAP Response (code 2) ID 1 length 171 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: No EAP Start, assuming it's an on-going EAP conversation Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) [eap] = updated Tue Sep 20 18:36:16 2016 : Debug: (1) } # authorize = updated Tue Sep 20 18:36:16 2016 : Debug: (1) Found Auth-Type = eap Tue Sep 20 18:36:16 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (1) authenticate { Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Expiring EAP session with state 0xc0a4b23ec0a5bf93 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Finished EAP session with state 0xc0a4b23ec0a5bf93 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Previous EAP request found for state 0xc0a4b23ec0a5bf93, released from the list Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Peer sent packet with method EAP TLS (13) Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Calling submodule eap_tls to process data Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: Continuing EAP-TLS Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: Peer sent flags --- Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: Got final TLS record fragment (165 bytes) Tue Sep 20 18:36:16 2016 : WARNING: (1) eap_tls: Total received TLS record fragments (165 bytes), does not equal indicated TLS record length (0 bytes) Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: [eaptls verify] = ok Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: Done initial handshake Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: (other): before/accept initialization Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: before/accept initialization Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: <<< recv TLS 1.2 [length 00a0] Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 read client hello A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: >>> send TLS 1.2 [length 0059] Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 write server hello A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: >>> send TLS 1.2 [length 0cdc] Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 write certificate A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: >>> send TLS 1.2 [length 024d] Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 write key exchange A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: >>> send TLS 1.2 [length 00c9] Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 write certificate request A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: SSLv3 flush data Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: In SSL Handshake Phase Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: In SSL Accept mode Tue Sep 20 18:36:16 2016 : Debug: (1) eap_tls: [eaptls process] = handled Tue Sep 20 18:36:16 2016 : Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 1014 Tue Sep 20 18:36:16 2016 : Debug: (1) eap: EAP session adding &reply:State = 0xc0a4b23ec1a6bf93 Tue Sep 20 18:36:16 2016 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Tue Sep 20 18:36:16 2016 : Debug: (1) [eap] = handled Tue Sep 20 18:36:16 2016 : Debug: (1) } # authenticate = handled Tue Sep 20 18:36:16 2016 : Debug: (1) Using Post-Auth-Type Challenge Tue Sep 20 18:36:16 2016 : Debug: (1) Post-Auth-Type sub-section not found. Ignoring. Tue Sep 20 18:36:16 2016 : Debug: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (1) session-state: Nothing to cache Tue Sep 20 18:36:16 2016 : Debug: (1) Sent Access-Challenge Id 0 from 192.168.1.210:1812 to 192.168.1.1:12227 length 0 Tue Sep 20 18:36:16 2016 : Debug: (1) EAP-Message = 0x010203f60dc00000105f160303005902000055030357e17390030b51541a414f064e44c9021cd20777f90080d0f2895ef078be5a6c2007a47c68a3113cfff90944183774ff03a7cc4540f666f39da6fec2423dcc029ac03000000dff01000100000b0004030001021603030cdc0b000cd8000cd50005de Tue Sep 20 18:36:16 2016 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000 Tue Sep 20 18:36:16 2016 : Debug: (1) State = 0xc0a4b23ec1a6bf931b6e88d496e35305 Tue Sep 20 18:36:16 2016 : Debug: (1) Finished request Tue Sep 20 18:36:16 2016 : Debug: Waking up in 4.9 seconds. Tue Sep 20 18:36:16 2016 : Debug: (1) Cleaning up request packet ID 0 with timestamp +3 Tue Sep 20 18:36:16 2016 : Debug: (2) Received Access-Request Id 0 from 192.168.1.1:12227 to 192.168.1.210:1812 length 292 Tue Sep 20 18:36:16 2016 : Debug: (2) User-Name = "pete@nexus5xp" Tue Sep 20 18:36:16 2016 : Debug: (2) NAS-IP-Address = 192.168.1.1 Tue Sep 20 18:36:16 2016 : Debug: (2) Called-Station-Id = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (2) Calling-Station-Id = "64bc0c4b27bf" Tue Sep 20 18:36:16 2016 : Debug: (2) NAS-Identifier = "305a3ac51d20" Tue Sep 20 18:36:16 2016 : Debug: (2) NAS-Port = 83 Tue Sep 20 18:36:16 2016 : Debug: (2) Framed-MTU = 1400 Tue Sep 20 18:36:16 2016 : Debug: (2) NAS-Port-Type = Wireless-802.11 Tue Sep 20 18:36:16 2016 : Debug: (2) EAP-Message = 0x020100ab0d0016030100a00100009c03038ef92dd289a9e47a08043ed8d17ba4aadbe9b997be545a3133beddda398a072b00003ec02cc030009fc02bc02f009ecca9cca8c00ac024c014c0280039006bc009c023c013c02700330067c007c011009d009c0035003d002f003c00050004000a01000035ff Tue Sep 20 18:36:16 2016 : Debug: (2) Message-Authenticator = 0x4e74d133cc690394c74156a7d305cf0f Tue Sep 20 18:36:16 2016 : Debug: (2) session-state: No State attribute Tue Sep 20 18:36:16 2016 : Debug: (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (2) authorize { Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) [preprocess] = ok Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 1 length 171 Tue Sep 20 18:36:16 2016 : Debug: (2) eap: No EAP Start, assuming it's an on-going EAP conversation Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) [eap] = updated Tue Sep 20 18:36:16 2016 : Debug: (2) } # authorize = updated Tue Sep 20 18:36:16 2016 : Debug: (2) Found Auth-Type = eap Tue Sep 20 18:36:16 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (2) authenticate { Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request Tue Sep 20 18:36:16 2016 : Debug: (2) eap: Failed in handler Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) [eap] = invalid Tue Sep 20 18:36:16 2016 : Debug: (2) } # authenticate = invalid Tue Sep 20 18:36:16 2016 : Debug: (2) Failed to authenticate the user Tue Sep 20 18:36:16 2016 : Auth: (2) Login incorrect: [pete@nexus5xp] (from client router-1 port 83 cli 64bc0c4b27bf) Tue Sep 20 18:36:16 2016 : Debug: (2) Using Post-Auth-Type Reject Tue Sep 20 18:36:16 2016 : Debug: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Sep 20 18:36:16 2016 : Debug: (2) Post-Auth-Type REJECT { Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 2 Tue Sep 20 18:36:16 2016 : Debug: %{User-Name} Tue Sep 20 18:36:16 2016 : Debug: Parsed xlat tree: Tue Sep 20 18:36:16 2016 : Debug: attribute --> User-Name Tue Sep 20 18:36:16 2016 : Debug: (2) attr_filter.access_reject: EXPAND %{User-Name} Tue Sep 20 18:36:16 2016 : Debug: (2) attr_filter.access_reject: --> pete@nexus5xp Tue Sep 20 18:36:16 2016 : Debug: (2) attr_filter.access_reject: Matched entry DEFAULT at line 11 Tue Sep 20 18:36:16 2016 : Debug: (2) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 2 Tue Sep 20 18:36:16 2016 : Debug: (2) [attr_filter.access_reject] = updated Tue Sep 20 18:36:16 2016 : Debug: (2) } # Post-Auth-Type REJECT = updated Tue Sep 20 18:36:16 2016 : Debug: (2) Delaying response for 1.000000 seconds Tue Sep 20 18:36:16 2016 : Debug: Waking up in 0.6 seconds. Tue Sep 20 18:36:16 2016 : Debug: Waking up in 0.3 seconds. Tue Sep 20 18:36:17 2016 : Debug: (2) Sending delayed response Tue Sep 20 18:36:17 2016 : Debug: (2) Sent Access-Reject Id 0 from 192.168.1.210:1812 to 192.168.1.1:12227 length 20 Tue Sep 20 18:36:17 2016 : Debug: Waking up in 3.9 seconds. Tue Sep 20 18:36:21 2016 : Debug: (2) Cleaning up request packet ID 0 with timestamp +3 Tue Sep 20 18:36:21 2016 : Info: Ready to process requests What am I missing? :) Kind regards Peter

2 2

EAP TLS cache help
by Dave Aldwinckle 20 Sep '16

20 Sep '16

Hi List, I recently configured TLS caching, but I'm seeing some odd behavior that I can't explain. Users are getting authenticated, but I can't tell if there are actually any cache hits. In debug I can see the files getting written to disk, but I can't find any log messages that indicate a session was resumed from the cache (maybe I'm not looking for the right message?) I'm also having a hard time explaining to myself why there are so many files being written. The cache expiry that I've set is 12 hours. [root@cn-aaa-4 tlscache]# pwd /fsys1/tlscache [root@cn-aaa-4 tlscache]# ls -l *.vps | wc -l 24579 I would expect a single user to have a few devices (laptop, phone, tablet, etc) but I'm seeing more than 20 cache files for some users, and I cleared the directory about an hour ago. In the following command I sorted by unique Stripped-User-Name and counted number of occurrences. The for loop is used because grep wouldn't let me feed it >25K files directly. The output has real user names, I've sanitized them for the list. [root@cn-aaa-4 tlscache]# (for i in 1 2 3 4 5 6 7 8 9 a b c d e f; do for j in 1 2 3 4 5 6 7 8 9 a b c d e f; do grep -h Stripped-User-Name ${i}${j}*.vps; done;done;) 2>/dev/null | sort | uniq -c | sort -nr | head 188 Stripped-User-Name = "someuser1" 96 Stripped-User-Name = "someuser2" 70 Stripped-User-Name = "someuser3" 62 Stripped-User-Name = "someuser4" 42 Stripped-User-Name = "someuser5" 36 Stripped-User-Name = "someuser6" 35 Stripped-User-Name = "someuser7" 34 Stripped-User-Name = "someuser8" 33 Stripped-User-Name = "someuser9" 32 Stripped-User-Name = "someuser10" # radiusd -v radiusd: FreeRADIUS Version 3.0.10, for host x86_64-redhat-linux-gnu, built on Oct 5 2015 at 16:30:01 Is that expected? Thanks, Dave

3 2