Freeradius-Users
Threads by month
- ----- 2026 -----
- July
- June
- May
- April
- March
- February
- January
- ----- 2025 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2024 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2023 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2022 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2021 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2020 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2019 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2018 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2017 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2016 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2015 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2014 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2013 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2012 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2011 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2010 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2009 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2008 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2007 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2006 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2005 -----
- December
- November
- October
- September
- August
- July
- June
- May
February 2016
- 87 participants
- 129 discussions
Hi everyone,
Our (Red Hat) QA was testing the effect of this entry in 3.0.4 ChangeLog:
* Modify pairparsevalue to deal with embedded NULLs better,
and use the binary versions of attribute values in rlm_ldap.
They have noticed that binary LDAP values get truncated on embedded zero
characters (\0) in RADIUS replies, in radiusReplyMessage in particular.
I.e. for
radiusReplyMessage:: cmVwbHkgd2l0aCBhAGI=
The response output by radtest was
Reply-Message = 'reply with a'
The network capture also showed that RADIUS reply packets contained truncated
values. Is this intended, or was there a fix for this?
In related discoveries, it seems that backslashes get removed from LDAP
attribute values in RADIUS replies, so
radiusReplyMessage: reply with a\0b
becomes
Reply-Message = 'reply with a0b'
in radtest output.
Is this intended?
Thank you.
Nick
4
12
Hello!
Let´s suppose the following situations:
1) User exists but the password is wrong
2) User does not exist
In both cases the answer is REJECT.
It happens that certain hardware is making endless attempts that eventually saturating the server.
- It is possible to cause the server, instead of rejecting the users, accept the login but responds ACCEPT with "framed-pool = pool-block" ?
or/and
- Is there any way to put REJECT users in a given group by default?
Thanks!
Fabricio
3
3
Hello,
Please help me set up freeradius2 + iODBC + Informix
(I'm newbie in freeradius).
- I have a test-machine with Ubuntu 14.04 and Freeradius-server
v2.1.12.
- I have a server with Informix Database Server v 10.00
Step 1:
- I installed unixODBC on test-machine
- I installed informix-csdk for connect to Informix Database
Server (Driver)
- I configured files /etc/odbc.ini and /etc/odbcinst.ini to
connect to Informix Database Server
- Checking with isql:
+++++++++++++++++++++++++++++++++++++++++
root@test:/home/test# isql -v work
+---------------------------------------+
| Connected! |
| |
| sql-statement |
| help [tablename] |
| quit |
| |
+---------------------------------------+
SQL> select 1 from TABLES(SET{1})
1
+++++++++++++++++++++++++++++++++++++++++
- Everything is allright.
Step 2:
- I try to install freeradius-iodbc module to connect to
Informix Database Server
- During install I get next warning:
+++++++++++++++++++++++++++++++++++++++++++++
The following packages will be REMOVED:
unixodbc unixodbc-dev
The following NEW packages will be installed:
libiodbc2-dev
+++++++++++++++++++++++++++++++++++++++++++++
- so unixodbc and unixodbc-dev packages was removed after
install freeradius-iodbc
- I included in radiusd.conf:
+++++++++++++++++++++++++++++++++++++++++++++
sql {
#
# Set the database to one of:
#
# mysql, mssql, oracle, postgresql
#
database = "iodbc"
#
# Which FreeRADIUS driver to use.
#
driver = "rlm_sql_${database}"
# Connection info:
server = "test.server.ru"
port = 1425
login = "test"
password = "test123"
radius_db = "test"
...
+++++++++++++++++++++++++++++++++++++++++++++
- freeradius -XXX showed me next error:
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
...
Fri Nov 21 14:53:48 2014 : Info: rlm_sql (sql): Driver
rlm_sql_iodbc (module rlm_sql_iodbc) loaded and linked
Fri Nov 21 14:53:48 2014 : Info: rlm_sql (sql): Attempting to
connect to test@test.server.ru:1425/test
Fri Nov 21 14:53:48 2014 : Debug: rlm_sql (sql): starting 0
Fri Nov 21 14:53:48 2014 : Info: rlm_sql (sql): Attempting to
connect rlm_sql_iodbc #0
Fri Nov 21 14:53:48 2014 : Error: sql_create_socket:
SQLConnectfailed: [iODBC][Driver Manager]Data source name
not found and no default driver specified. Driver could not be
loaded
Fri Nov 21 14:53:48 2014 : Error: rlm_sql (sql): Failed to
connect DB handle #0
...
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
- Error - "SQLConnectfailed: [iODBC][Driver Manager]Data
source name not found and no default driver specified. Driver
could not be loaded."
- Where did I go wrong?
- I found some information in net with same problem, but clear
decision nowhere not found.
4
4
Hello, I'm currently running FreeRADIUS 3.0.4 on a CentOS server and I
wanted to use RadPerf for testing. Since I cannot install RadPerf in
CentOS, I installed RadPerf in a separate Ubuntu 14.04 server, my
question is: which is better for RadPerf installation? on the same
server where FreeRADIUS was installed or different server?
4
4
Hi all,
I'm trying to understand how to configure radius Time Limit, Data download
Limit, .. On a FreeRadius 3.0.10 using mysql and Mikrotik.
First of all I wold like to know about to configure mikrotik dictionary
(http://wiki.mikrotik.com/wiki/Manual:RADIUS_Client/vendor_dictionary)
What I should do create
${prefix}/share/freeradius/dictionary/mikrotik.dictionary
and add INCLUDE into raddb/dictionary ?
or just add all lines into
/etc/raddb/dictionary ?
Where I should use the dictionary attributes on modules ?
Then on mods-available there is sqlcounter with some configurations.
Is there any other examples somewhere ?
I need data limitation.
And is it possible to create some group of users with diferents restrictions
?
Thanks.
3
15
I'm trying to set some request temporary variables that I can use further
down in the flow for lookups.
update request {
RealmLookup := "ou=Realms"
}
ldap.nodeauth
But when it comes to do the lookup, the = and , get escaped so it makes an
invalid DN.
(0) update request {
(0) RealmLookup := "ou=Realms,"
(0) } # update request = noop
rlm_ldap (ldap.nodeauth): Reserved connection (0)
(0) ldap.nodeauth: EXPAND (cn=%{AuthCred})
(0) ldap.nodeauth: --> (cn=m2m)
(0) ldap.nodeauth: EXPAND %{RealmLookup}ou=Proxy
(0) ldap.nodeauth: --> ou\3dRealms\2cou=Proxy
(0) ldap.nodeauth: Performing search in "ou\3dRealms\2cou=Proxy" with
filter "(cn=m2m)", scope "sub"
(0) ldap.nodeauth: Waiting for search result...
(0) ldap.nodeauth: ERROR: Failed performing search: Invalid DN syntax
Any way to stop the xlat from expanding the value, I've tried unescape and
a number of different options without success?
Or will I need to just define multiple modules with different DNs of the
places I would like to search in the hierarchy.
5
9
I'm trying to allow unmetered content over my network. Just shy of 1000 users.
I'm looking to use freeradius for this, and want to know if/how it's possible.
I don't think it's possible/under the purview of freeradius itself to distinguish between metered and unmetered traffic, I can have it done by another device and just come in on different physical ports on the machine.
My first thoughts are having freeradius virtual servers defined. I can have the unmetered and metered traffic come in on different physical ports with separate IPs.
The first port takes the metered content and authentication to one virtual server.
The second port takes the unmetered content, with authentication proxied to the other virtual server.
Then I'd measure data usage for both metered/unmetered networks by looking into each of the accounting tables for the virtual servers.
Is this how it would work? How else could it be done? Are there any how-tos?
Joshua C
2
5
In our EAP-PEAP sessions, the typical conversation length is 10 packets.
We have TLS caching enabled, but I noticed the TLS cache is populated
during packet 4, which is before processing has started on the tunneled
authentication.
Is it possible to force an update of the cache entry from the
inner-tunnel server e.g. to add attributes that are only available at
this stage? I attempted to call an update by doing this in the
inner-tunnel server:
update control {
Cache-TTL := 0
}
cache_tls_session
This caused authentications to fail with "cache_tls_session (fail)" and
no further information is given. Is it possible to do this?
Thanks,
Jonathan
3
11
Hello freeradius users,
i install a freeradius 3 with mysql and daloradius on ubuntu 14.04 lts.
Now i trie to get the radius authentification working with a hp procurve 2530 switch.
But the Radius Server does not send any Access-Accept Message.
Only Access-Challanges will send tot he switch:
Logfile:
Fri Feb 26 09:09:12 2016 : Debug: Server was built with:
Fri Feb 26 09:09:12 2016 : Debug: accounting : yes
Fri Feb 26 09:09:12 2016 : Debug: authentication : yes
Fri Feb 26 09:09:12 2016 : Debug: ascend-binary-attributes : yes
Fri Feb 26 09:09:12 2016 : Debug: coa : yes
Fri Feb 26 09:09:12 2016 : Debug: control-socket : yes
Fri Feb 26 09:09:12 2016 : Debug: detail : yes
Fri Feb 26 09:09:12 2016 : Debug: dhcp : yes
Fri Feb 26 09:09:12 2016 : Debug: dynamic-clients : yes
Fri Feb 26 09:09:12 2016 : Debug: osfc2 : no
Fri Feb 26 09:09:12 2016 : Debug: proxy : yes
Fri Feb 26 09:09:12 2016 : Debug: regex-pcre : no
Fri Feb 26 09:09:12 2016 : Debug: regex-posix : yes
Fri Feb 26 09:09:12 2016 : Debug: regex-posix-extended : yes
Fri Feb 26 09:09:12 2016 : Debug: session-management : yes
Fri Feb 26 09:09:12 2016 : Debug: stats : yes
Fri Feb 26 09:09:12 2016 : Debug: tcp : yes
Fri Feb 26 09:09:12 2016 : Debug: threads : yes
Fri Feb 26 09:09:12 2016 : Debug: tls : yes
Fri Feb 26 09:09:12 2016 : Debug: unlang : yes
Fri Feb 26 09:09:12 2016 : Debug: vmps : yes
Fri Feb 26 09:09:12 2016 : Debug: developer : no
Fri Feb 26 09:09:12 2016 : Debug: Server core libs:
Fri Feb 26 09:09:12 2016 : Debug: freeradius-server : 3.0.10
Fri Feb 26 09:09:12 2016 : Debug: talloc : 2.0.*
Fri Feb 26 09:09:12 2016 : Debug: ssl : 1.0.1f release
Fri Feb 26 09:09:12 2016 : Debug: Endianness:
Fri Feb 26 09:09:12 2016 : Debug: little
Fri Feb 26 09:09:12 2016 : Debug: Compilation flags:
Fri Feb 26 09:09:12 2016 : Info: Copyright (C) 1999-2015 The FreeRADIUS server project and contributors
Fri Feb 26 09:09:12 2016 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Fri Feb 26 09:09:12 2016 : Info: PARTICULAR PURPOSE
Fri Feb 26 09:09:12 2016 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Fri Feb 26 09:09:12 2016 : Info: GNU General Public License
Fri Feb 26 09:09:12 2016 : Info: For more information about these matters, see the file named COPYRIGHT
Fri Feb 26 09:09:12 2016 : Info: Starting - reading configuration files ...
Fri Feb 26 09:09:12 2016 : Debug: including dictionary file /usr/share/freeradius/dictionary
Fri Feb 26 09:09:12 2016 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcp
Fri Feb 26 09:09:12 2016 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqp
Fri Feb 26 09:09:12 2016 : Debug: including dictionary file /etc/freeradius/dictionary
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/radiusd.conf
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/proxy.conf
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/clients.conf
Fri Feb 26 09:09:12 2016 : Debug: including files in directory /etc/freeradius/mods-enabled/
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/linelog
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/soh
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/passwd
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/replicate
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/dynamic_clients
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/mschap
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/expr
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/cache_eap
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/files
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/unpack
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/utf8
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/unix
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/chap
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/detail
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/ntlm_auth
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/preprocess
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/exec
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/sql
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-config/sql/main/sqlite/queries.conf
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/logintime
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/sradutmp
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/digest
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/radutmp
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/eap
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/pap
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/expiration
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/mods-enabled/echo
Fri Feb 26 09:09:12 2016 : Debug: including files in directory /etc/freeradius/policy.d/
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/abfab-tr
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/control
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/cui
Fri Feb 26 09:09:12 2016 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE
Fri Feb 26 09:09:12 2016 : Debug: OPTIMIZING (no == yes) --> FALSE
Fri Feb 26 09:09:12 2016 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE
Fri Feb 26 09:09:12 2016 : Debug: OPTIMIZING (no == yes) --> FALSE
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/dhcp
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/accounting
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/canonicalization
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/debug
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/operator-name
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/filter
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/policy.d/eap
Fri Feb 26 09:09:12 2016 : Debug: including files in directory /etc/freeradius/sites-enabled/
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Fri Feb 26 09:09:12 2016 : Debug: including files in directory /etc/freeradius/sites-enabled/
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:12 2016 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel
Fri Feb 26 09:09:12 2016 : Debug: main {
Fri Feb 26 09:09:12 2016 : Debug: security {
Fri Feb 26 09:09:12 2016 : Debug: user = "freerad"
Fri Feb 26 09:09:12 2016 : Debug: group = "freerad"
Fri Feb 26 09:09:12 2016 : Debug: allow_core_dumps = no
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[462]: The item 'max_attributes' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[480]: The item 'reject_delay' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[500]: The item 'status_server' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: name = "freeradius"
Fri Feb 26 09:09:12 2016 : Debug: prefix = "/usr"
Fri Feb 26 09:09:12 2016 : Debug: localstatedir = "/var"
Fri Feb 26 09:09:12 2016 : Debug: logdir = "/var/log/freeradius"
Fri Feb 26 09:09:12 2016 : Debug: run_dir = "/var/run/freeradius"
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[372]: The item 'checkrad' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[521]: The item 'proxy_requests' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: main {
Fri Feb 26 09:09:12 2016 : Debug: name = "freeradius"
Fri Feb 26 09:09:12 2016 : Debug: prefix = "/usr"
Fri Feb 26 09:09:12 2016 : Debug: localstatedir = "/var"
Fri Feb 26 09:09:12 2016 : Debug: sbindir = "/usr/sbin"
Fri Feb 26 09:09:12 2016 : Debug: logdir = "/var/log/freeradius"
Fri Feb 26 09:09:12 2016 : Debug: run_dir = "/var/run/freeradius"
Fri Feb 26 09:09:12 2016 : Debug: libdir = "/usr/lib/freeradius"
Fri Feb 26 09:09:12 2016 : Debug: radacctdir = "/var/log/freeradius/radacct"
Fri Feb 26 09:09:12 2016 : Debug: hostname_lookups = no
Fri Feb 26 09:09:12 2016 : Debug: max_request_time = 30
Fri Feb 26 09:09:12 2016 : Debug: cleanup_delay = 5
Fri Feb 26 09:09:12 2016 : Debug: max_requests = 16384
Fri Feb 26 09:09:12 2016 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"
Fri Feb 26 09:09:12 2016 : Debug: checkrad = "/usr/sbin/checkrad"
Fri Feb 26 09:09:12 2016 : Debug: debug_level = 0
Fri Feb 26 09:09:12 2016 : Debug: proxy_requests = yes
Fri Feb 26 09:09:12 2016 : Debug: log {
Fri Feb 26 09:09:12 2016 : Debug: stripped_names = no
Fri Feb 26 09:09:12 2016 : Debug: auth = no
Fri Feb 26 09:09:12 2016 : Debug: auth_badpass = no
Fri Feb 26 09:09:12 2016 : Debug: auth_goodpass = no
Fri Feb 26 09:09:12 2016 : Debug: colourise = yes
Fri Feb 26 09:09:12 2016 : Debug: msg_denied = "You are already logged in - access denied"
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[331]: The item 'syslog_facility' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: resources {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: security {
Fri Feb 26 09:09:12 2016 : Debug: max_attributes = 200
Fri Feb 26 09:09:12 2016 : Debug: reject_delay = 1.000000
Fri Feb 26 09:09:12 2016 : Debug: status_server = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Warning: /etc/freeradius/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Feb 26 09:09:12 2016 : Debug: proxy server {
Fri Feb 26 09:09:12 2016 : Debug: retry_delay = 5
Fri Feb 26 09:09:12 2016 : Debug: retry_count = 3
Fri Feb 26 09:09:12 2016 : Debug: default_fallback = no
Fri Feb 26 09:09:12 2016 : Debug: dead_time = 120
Fri Feb 26 09:09:12 2016 : Debug: wake_all_if_all_dead = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: home_server localhost {
Fri Feb 26 09:09:12 2016 : Debug: ipaddr = 127.0.0.1
Fri Feb 26 09:09:12 2016 : Debug: port = 1812
Fri Feb 26 09:09:12 2016 : Debug: type = "auth"
Fri Feb 26 09:09:12 2016 : Debug: secret = "testing123"
Fri Feb 26 09:09:12 2016 : Debug: response_window = 20.000000
Fri Feb 26 09:09:12 2016 : Debug: response_timeouts = 1
Fri Feb 26 09:09:12 2016 : Debug: max_outstanding = 65536
Fri Feb 26 09:09:12 2016 : Debug: zombie_period = 40
Fri Feb 26 09:09:12 2016 : Debug: status_check = "status-server"
Fri Feb 26 09:09:12 2016 : Debug: ping_interval = 30
Fri Feb 26 09:09:12 2016 : Debug: check_interval = 30
Fri Feb 26 09:09:12 2016 : Debug: check_timeout = 4
Fri Feb 26 09:09:12 2016 : Debug: num_answers_to_alive = 3
Fri Feb 26 09:09:12 2016 : Debug: revive_interval = 120
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: max_requests = 0
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 0
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: coa {
Fri Feb 26 09:09:12 2016 : Debug: irt = 2
Fri Feb 26 09:09:12 2016 : Debug: mrt = 16
Fri Feb 26 09:09:12 2016 : Debug: mrc = 5
Fri Feb 26 09:09:12 2016 : Debug: mrd = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: home_server_pool my_auth_failover {
Fri Feb 26 09:09:12 2016 : Debug: type = fail-over
Fri Feb 26 09:09:12 2016 : Debug: home_server = localhost
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: realm example.com {
Fri Feb 26 09:09:12 2016 : Debug: auth_pool = my_auth_failover
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: realm LOCAL {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: radiusd: #### Loading Clients ####
Fri Feb 26 09:09:12 2016 : Debug: client localhost {
Fri Feb 26 09:09:12 2016 : Debug: ipaddr = 127.0.0.1
Fri Feb 26 09:09:12 2016 : Debug: require_message_authenticator = no
Fri Feb 26 09:09:12 2016 : Debug: secret = "testing123"
Fri Feb 26 09:09:12 2016 : Debug: nas_type = "other"
Fri Feb 26 09:09:12 2016 : Debug: proto = "*"
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32
Fri Feb 26 09:09:12 2016 : Debug: client localhost_ipv6 {
Fri Feb 26 09:09:12 2016 : Debug: ipv6addr = ::1
Fri Feb 26 09:09:12 2016 : Debug: require_message_authenticator = no
Fri Feb 26 09:09:12 2016 : Debug: secret = "testing123"
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Adding client ::1/128 (::1) to prefix tree 128
Fri Feb 26 09:09:12 2016 : Info: Debugger not attached
Fri Feb 26 09:09:12 2016 : Debug: # Creating Auth-Type = digest
Fri Feb 26 09:09:12 2016 : Debug: radiusd: #### Instantiating modules ####
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_linelog.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_linelog, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_linelog
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "linelog" from file /etc/freeradius/mods-enabled/linelog
Fri Feb 26 09:09:12 2016 : Debug: linelog {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/linelog"
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: syslog_severity = "info"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: format = "This is a log message for %{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "log_accounting" from file /etc/freeradius/mods-enabled/linelog
Fri Feb 26 09:09:12 2016 : Debug: linelog log_accounting {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/linelog-accounting"
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: syslog_severity = "info"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: format = ""
Fri Feb 26 09:09:12 2016 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_soh.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_soh, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_soh
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "soh" from file /etc/freeradius/mods-enabled/soh
Fri Feb 26 09:09:12 2016 : Debug: soh {
Fri Feb 26 09:09:12 2016 : Debug: dhcp = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_passwd.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_passwd, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_passwd
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd
Fri Feb 26 09:09:12 2016 : Debug: passwd etc_passwd {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/passwd"
Fri Feb 26 09:09:12 2016 : Debug: format = "*User-Name:Crypt-Password:"
Fri Feb 26 09:09:12 2016 : Debug: delimiter = ":"
Fri Feb 26 09:09:12 2016 : Debug: ignore_nislike = no
Fri Feb 26 09:09:12 2016 : Debug: ignore_empty = yes
Fri Feb 26 09:09:12 2016 : Debug: allow_multiple_keys = no
Fri Feb 26 09:09:12 2016 : Debug: hash_size = 100
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_replicate.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_replicate, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_replicate
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "replicate" from file /etc/freeradius/mods-enabled/replicate
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_dynamic_clients.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_dynamic_clients, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_dynamic_clients
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/mods-enabled/dynamic_clients
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_mschap.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_mschap, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_mschap
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "mschap" from file /etc/freeradius/mods-enabled/mschap
Fri Feb 26 09:09:12 2016 : Debug: mschap {
Fri Feb 26 09:09:12 2016 : Debug: use_mppe = yes
Fri Feb 26 09:09:12 2016 : Debug: require_encryption = no
Fri Feb 26 09:09:12 2016 : Debug: require_strong = no
Fri Feb 26 09:09:12 2016 : Debug: with_ntdomain_hack = yes
Fri Feb 26 09:09:12 2016 : Debug: passchange {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: allow_retry = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_expr.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_expr, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_expr
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "expr" from file /etc/freeradius/mods-enabled/expr
Fri Feb 26 09:09:12 2016 : Debug: expr {
Fri Feb 26 09:09:12 2016 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_cache.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_cache, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_cache
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap
Fri Feb 26 09:09:12 2016 : Debug: cache cache_eap {
Fri Feb 26 09:09:12 2016 : Debug: driver = "rlm_cache_rbtree"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
Fri Feb 26 09:09:12 2016 : Debug: ttl = 15
Fri Feb 26 09:09:12 2016 : Debug: max_entries = 0
Fri Feb 26 09:09:12 2016 : Debug: epoch = 0
Fri Feb 26 09:09:12 2016 : Debug: add_stats = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_files.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_files, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_files
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "files" from file /etc/freeradius/mods-enabled/files
Fri Feb 26 09:09:12 2016 : Debug: files {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/files/authorize"
Fri Feb 26 09:09:12 2016 : Debug: acctusersfile = "/etc/freeradius/mods-config/files/accounting"
Fri Feb 26 09:09:12 2016 : Debug: preproxy_usersfile = "/etc/freeradius/mods-config/files/pre-proxy"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_unpack.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_unpack, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_unpack
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "unpack" from file /etc/freeradius/mods-enabled/unpack
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_detail.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_detail, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_detail
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "auth_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: detail auth_log {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
Fri Feb 26 09:09:12 2016 : Debug: header = "%t"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: locking = no
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: log_packet_header = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "reply_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: detail reply_log {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
Fri Feb 26 09:09:12 2016 : Debug: header = "%t"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: locking = no
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: log_packet_header = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: detail pre_proxy_log {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
Fri Feb 26 09:09:12 2016 : Debug: header = "%t"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: locking = no
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: log_packet_header = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: detail post_proxy_log {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
Fri Feb 26 09:09:12 2016 : Debug: header = "%t"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: locking = no
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: log_packet_header = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_utf8.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_utf8, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_utf8
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "utf8" from file /etc/freeradius/mods-enabled/utf8
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_always.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_always, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_always
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "reject" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always reject {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "reject"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "fail" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always fail {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "fail"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "ok" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always ok {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "ok"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "handled" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always handled {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "handled"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "invalid" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always invalid {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "invalid"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "userlock" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always userlock {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "userlock"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "notfound" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always notfound {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "notfound"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "noop" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always noop {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "noop"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "updated" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: always updated {
Fri Feb 26 09:09:12 2016 : Debug: rcode = "updated"
Fri Feb 26 09:09:12 2016 : Debug: simulcount = 0
Fri Feb 26 09:09:12 2016 : Debug: mpp = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_unix.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_unix, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_unix
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "unix" from file /etc/freeradius/mods-enabled/unix
Fri Feb 26 09:09:12 2016 : Debug: unix {
Fri Feb 26 09:09:12 2016 : Debug: radwtmp = "/var/log/freeradius/radwtmp"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Creating attribute Unix-Group
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_chap.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_chap, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_chap
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "chap" from file /etc/freeradius/mods-enabled/chap
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "detail" from file /etc/freeradius/mods-enabled/detail
Fri Feb 26 09:09:12 2016 : Debug: detail {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Fri Feb 26 09:09:12 2016 : Debug: header = "%t"
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: locking = no
Fri Feb 26 09:09:12 2016 : Debug: escape_filenames = no
Fri Feb 26 09:09:12 2016 : Debug: log_packet_header = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_exec.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_exec, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_exec
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/mods-enabled/ntlm_auth
Fri Feb 26 09:09:12 2016 : Debug: exec ntlm_auth {
Fri Feb 26 09:09:12 2016 : Debug: wait = yes
Fri Feb 26 09:09:12 2016 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
Fri Feb 26 09:09:12 2016 : Debug: shell_escape = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_attr_filter.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_attr_filter, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_attr_filter
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: attr_filter attr_filter.post-proxy {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/post-proxy"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{Realm}"
Fri Feb 26 09:09:12 2016 : Debug: relaxed = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: attr_filter attr_filter.pre-proxy {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/pre-proxy"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{Realm}"
Fri Feb 26 09:09:12 2016 : Debug: relaxed = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: attr_filter attr_filter.access_reject {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/access_reject"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: relaxed = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: attr_filter attr_filter.access_challenge {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/access_challenge"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: relaxed = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: attr_filter attr_filter.accounting_response {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/accounting_response"
Fri Feb 26 09:09:12 2016 : Debug: key = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: relaxed = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_preprocess.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_preprocess, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_preprocess
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "preprocess" from file /etc/freeradius/mods-enabled/preprocess
Fri Feb 26 09:09:12 2016 : Debug: preprocess {
Fri Feb 26 09:09:12 2016 : Debug: huntgroups = "/etc/freeradius/mods-config/preprocess/huntgroups"
Fri Feb 26 09:09:12 2016 : Debug: hints = "/etc/freeradius/mods-config/preprocess/hints"
Fri Feb 26 09:09:12 2016 : Debug: with_ascend_hack = no
Fri Feb 26 09:09:12 2016 : Debug: ascend_channels_per_line = 23
Fri Feb 26 09:09:12 2016 : Debug: with_ntdomain_hack = no
Fri Feb 26 09:09:12 2016 : Debug: with_specialix_jetstream_hack = no
Fri Feb 26 09:09:12 2016 : Debug: with_cisco_vsa_hack = no
Fri Feb 26 09:09:12 2016 : Debug: with_alvarion_vsa_hack = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_realm.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_realm, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_realm
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "IPASS" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: realm IPASS {
Fri Feb 26 09:09:12 2016 : Debug: format = "prefix"
Fri Feb 26 09:09:12 2016 : Debug: delimiter = "/"
Fri Feb 26 09:09:12 2016 : Debug: ignore_default = no
Fri Feb 26 09:09:12 2016 : Debug: ignore_null = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "suffix" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: realm suffix {
Fri Feb 26 09:09:12 2016 : Debug: format = "suffix"
Fri Feb 26 09:09:12 2016 : Debug: delimiter = "@"
Fri Feb 26 09:09:12 2016 : Debug: ignore_default = no
Fri Feb 26 09:09:12 2016 : Debug: ignore_null = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "realmpercent" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: realm realmpercent {
Fri Feb 26 09:09:12 2016 : Debug: format = "suffix"
Fri Feb 26 09:09:12 2016 : Debug: delimiter = "%"
Fri Feb 26 09:09:12 2016 : Debug: ignore_default = no
Fri Feb 26 09:09:12 2016 : Debug: ignore_null = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "ntdomain" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: realm ntdomain {
Fri Feb 26 09:09:12 2016 : Debug: format = "prefix"
Fri Feb 26 09:09:12 2016 : Debug: delimiter = "\\"
Fri Feb 26 09:09:12 2016 : Debug: ignore_default = no
Fri Feb 26 09:09:12 2016 : Debug: ignore_null = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "exec" from file /etc/freeradius/mods-enabled/exec
Fri Feb 26 09:09:12 2016 : Debug: exec {
Fri Feb 26 09:09:12 2016 : Debug: wait = no
Fri Feb 26 09:09:12 2016 : Debug: input_pairs = "request"
Fri Feb 26 09:09:12 2016 : Debug: shell_escape = yes
Fri Feb 26 09:09:12 2016 : Debug: timeout = 10
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_sql.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_sql, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_sql
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "sql" from file /etc/freeradius/mods-enabled/sql
Fri Feb 26 09:09:12 2016 : Debug: sql {
Fri Feb 26 09:09:12 2016 : Debug: driver = "rlm_sql_mysql"
Fri Feb 26 09:09:12 2016 : Debug: server = "localhost"
Fri Feb 26 09:09:12 2016 : Debug: port = 3306
Fri Feb 26 09:09:12 2016 : Debug: login = "freeradius"
Fri Feb 26 09:09:12 2016 : Debug: password = "radius123"
Fri Feb 26 09:09:12 2016 : Debug: radius_db = "radius"
Fri Feb 26 09:09:12 2016 : Debug: read_groups = yes
Fri Feb 26 09:09:12 2016 : Debug: read_profiles = yes
Fri Feb 26 09:09:12 2016 : Debug: read_clients = yes
Fri Feb 26 09:09:12 2016 : Debug: delete_stale_sessions = yes
Fri Feb 26 09:09:12 2016 : Debug: sql_user_name = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: default_user_profile = ""
Fri Feb 26 09:09:12 2016 : Debug: client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
Fri Feb 26 09:09:12 2016 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id"
Fri Feb 26 09:09:12 2016 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id"
Fri Feb 26 09:09:12 2016 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id"
Fri Feb 26 09:09:12 2016 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id"
Fri Feb 26 09:09:12 2016 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority"
Fri Feb 26 09:09:12 2016 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-Group}' AND acctstoptime IS NULL"
Fri Feb 26 09:09:12 2016 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Fri Feb 26 09:09:12 2016 : Debug: accounting {
Fri Feb 26 09:09:12 2016 : Debug: reference = "%{tolower:type.%{Acct-Status-Type}.query}"
Fri Feb 26 09:09:12 2016 : Debug: type {
Fri Feb 26 09:09:12 2016 : Debug: accounting-on {
Fri Feb 26 09:09:12 2016 : Debug: query = "UPDATE radacct SET acctstoptime = %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime = (%{%{integer:Event-Timestamp}:-strftime('%%s', 'now')} - strftime('%%s', acctstarttime)), acctterminatecause = '%{Acct-Terminate-Cause}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= %{integer:Event-Timestamp}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: accounting-off {
Fri Feb 26 09:09:12 2016 : Debug: query = "UPDATE radacct SET acctstoptime = %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime = (%{%{integer:Event-Timestamp}:-strftime('%%s', 'now')} - strftime('%%s', acctstarttime)), acctterminatecause = '%{Acct-Terminate-Cause}' WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= %{integer:Event-Timestamp}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: start {
Fri Feb 26 09:09:12 2016 : Debug: query = "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', %{%{integer:Event-Timestamp}:-date('now')}, %{%{integer:Event-Timestamp}:-date('now')}, NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: interim-update {
Fri Feb 26 09:09:12 2016 : Debug: query = "UPDATE radacct SET acctupdatetime = %{%{integer:Event-Timestamp}:-date('now')}, acctinterval = 0, framedipaddress = '%{Framed-IP-Address}', acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = %{%{Acct-Input-Gigawords}:-0} << 32 | %{%{Acct-Input-Octets}:-0}, acctoutputoctets = %{%{Acct-Output-Gigawords}:-0} << 32 | %{%{Acct-Output-Octets}:-0} WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: stop {
Fri Feb 26 09:09:12 2016 : Debug: query = "UPDATE radacct SET acctstoptime = %{%{integer:Event-Timestamp}:-date('now')}, acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = %{%{Acct-Input-Gigawords}:-0} << 32 | %{%{Acct-Input-Octets}:-0}, acctoutputoctets = %{%{Acct-Output-Gigawords}:-0} << 32 | %{%{Acct-Output-Octets}:-0}, acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: post-auth {
Fri Feb 26 09:09:12 2016 : Debug: reference = ".query"
Fri Feb 26 09:09:12 2016 : Debug: query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_sql_mysql.so"
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Fri Feb 26 09:09:12 2016 : Debug: Creating attribute SQL-Group
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_logintime.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_logintime, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_logintime
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "logintime" from file /etc/freeradius/mods-enabled/logintime
Fri Feb 26 09:09:12 2016 : Debug: logintime {
Fri Feb 26 09:09:12 2016 : Debug: minimum_timeout = 60
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_radutmp.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_radutmp, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_radutmp
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "sradutmp" from file /etc/freeradius/mods-enabled/sradutmp
Fri Feb 26 09:09:12 2016 : Debug: radutmp sradutmp {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/sradutmp"
Fri Feb 26 09:09:12 2016 : Debug: username = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: case_sensitive = yes
Fri Feb 26 09:09:12 2016 : Debug: check_with_nas = yes
Fri Feb 26 09:09:12 2016 : Debug: permissions = 420
Fri Feb 26 09:09:12 2016 : Debug: caller_id = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_digest.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_digest, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_digest
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "digest" from file /etc/freeradius/mods-enabled/digest
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "radutmp" from file /etc/freeradius/mods-enabled/radutmp
Fri Feb 26 09:09:12 2016 : Debug: radutmp {
Fri Feb 26 09:09:12 2016 : Debug: filename = "/var/log/freeradius/radutmp"
Fri Feb 26 09:09:12 2016 : Debug: username = "%{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: case_sensitive = yes
Fri Feb 26 09:09:12 2016 : Debug: check_with_nas = yes
Fri Feb 26 09:09:12 2016 : Debug: permissions = 384
Fri Feb 26 09:09:12 2016 : Debug: caller_id = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_eap, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_eap
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "eap" from file /etc/freeradius/mods-enabled/eap
Fri Feb 26 09:09:12 2016 : Debug: eap {
Fri Feb 26 09:09:12 2016 : Debug: default_eap_type = "md5"
Fri Feb 26 09:09:12 2016 : Debug: timer_expire = 60
Fri Feb 26 09:09:12 2016 : Debug: ignore_unknown_eap_types = no
Fri Feb 26 09:09:12 2016 : Debug: cisco_accounting_username_bug = no
Fri Feb 26 09:09:12 2016 : Debug: max_sessions = 16384
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_pap.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_pap, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_pap
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "pap" from file /etc/freeradius/mods-enabled/pap
Fri Feb 26 09:09:12 2016 : Debug: pap {
Fri Feb 26 09:09:12 2016 : Debug: normalise = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_expiration.so"
Fri Feb 26 09:09:12 2016 : Debug: Loaded rlm_expiration, checking if it's valid
Fri Feb 26 09:09:12 2016 : Debug: # Loaded module rlm_expiration
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "expiration" from file /etc/freeradius/mods-enabled/expiration
Fri Feb 26 09:09:12 2016 : Debug: # Loading module "echo" from file /etc/freeradius/mods-enabled/echo
Fri Feb 26 09:09:12 2016 : Debug: exec echo {
Fri Feb 26 09:09:12 2016 : Debug: wait = yes
Fri Feb 26 09:09:12 2016 : Debug: program = "/bin/echo %{User-Name}"
Fri Feb 26 09:09:12 2016 : Debug: input_pairs = "request"
Fri Feb 26 09:09:12 2016 : Debug: output_pairs = "reply"
Fri Feb 26 09:09:12 2016 : Debug: shell_escape = yes
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: instantiate {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: modules {
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "linelog" from file /etc/freeradius/mods-enabled/linelog
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/mods-enabled/linelog
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd
Fri Feb 26 09:09:12 2016 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "mschap" from file /etc/freeradius/mods-enabled/mschap
Fri Feb 26 09:09:12 2016 : Debug: rlm_mschap (mschap): using internal authentication
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_cache_rbtree.so"
Fri Feb 26 09:09:12 2016 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "files" from file /etc/freeradius/mods-enabled/files
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/files/authorize
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/files/accounting
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/files/pre-proxy
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "reject" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "fail" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "ok" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "handled" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "invalid" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "userlock" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "notfound" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "noop" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "updated" from file /etc/freeradius/mods-enabled/always
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "detail" from file /etc/freeradius/mods-enabled/detail
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/post-proxy
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/pre-proxy
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/access_reject
Fri Feb 26 09:09:12 2016 : Warning: [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT".
Fri Feb 26 09:09:12 2016 : Warning: [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT".
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/access_challenge
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/accounting_response
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/mods-enabled/preprocess
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/preprocess/huntgroups
Fri Feb 26 09:09:12 2016 : Debug: reading pairlist file /etc/freeradius/mods-config/preprocess/hints
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "suffix" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/mods-enabled/realm
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "sql" from file /etc/freeradius/mods-enabled/sql
Fri Feb 26 09:09:12 2016 : Info: rlm_sql_mysql: libmysql version: 5.5.47
Fri Feb 26 09:09:12 2016 : Debug: mysql {
Fri Feb 26 09:09:12 2016 : Debug: tls {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: warnings = "auto"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Attempting to connect to database "radius"
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Using local pool section
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): No pool reference found for config item "sql.pool"
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Initialising connection pool
Fri Feb 26 09:09:12 2016 : Debug: pool {
Fri Feb 26 09:09:12 2016 : Debug: start = 5
Fri Feb 26 09:09:12 2016 : Debug: min = 3
Fri Feb 26 09:09:12 2016 : Debug: max = 32
Fri Feb 26 09:09:12 2016 : Debug: spare = 10
Fri Feb 26 09:09:12 2016 : Debug: uses = 0
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: cleanup_interval = 30
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 60
Fri Feb 26 09:09:12 2016 : Debug: retry_delay = 30
Fri Feb 26 09:09:12 2016 : Debug: spread = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (0), 1 of 32 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (2), 1 of 30 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (4), 1 of 28 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Adding pool reference 0x1e41e70 to config item "sql.pool"
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Processing generate_sql_clients
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Reserved connection (0)
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Executing select query: SELECT id, nasname, shortname, type, secret, server FROM nas
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Adding client 192.168.6.0/24 () to global clients list
Fri Feb 26 09:09:12 2016 : Debug: Adding client 192.168.6.0/24 (192.168.6.0) to prefix tree 24
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (192.168.6.0): Client "" (sql) added
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql (sql): Released connection (0)
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Need 5 more connections to reach 10 spares
Fri Feb 26 09:09:12 2016 : Info: rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:12 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "logintime" from file /etc/freeradius/mods-enabled/logintime
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "eap" from file /etc/freeradius/mods-enabled/eap
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_md5.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_md5
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_leap.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_leap
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_gtc.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_gtc
Fri Feb 26 09:09:12 2016 : Debug: gtc {
Fri Feb 26 09:09:12 2016 : Debug: challenge = "Password: "
Fri Feb 26 09:09:12 2016 : Debug: auth_type = "PAP"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_tls.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_tls
Fri Feb 26 09:09:12 2016 : Debug: tls {
Fri Feb 26 09:09:12 2016 : Debug: tls = "tls-common"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: tls-config tls-common {
Fri Feb 26 09:09:12 2016 : Debug: rsa_key_exchange = no
Fri Feb 26 09:09:12 2016 : Debug: dh_key_exchange = yes
Fri Feb 26 09:09:12 2016 : Debug: rsa_key_length = 512
Fri Feb 26 09:09:12 2016 : Debug: dh_key_length = 512
Fri Feb 26 09:09:12 2016 : Debug: verify_depth = 0
Fri Feb 26 09:09:12 2016 : Debug: ca_path = "/etc/freeradius/certs"
Fri Feb 26 09:09:12 2016 : Debug: pem_file_type = yes
Fri Feb 26 09:09:12 2016 : Debug: private_key_file = "/etc/freeradius/certs/server.pem"
Fri Feb 26 09:09:12 2016 : Debug: certificate_file = "/etc/freeradius/certs/server.pem"
Fri Feb 26 09:09:12 2016 : Debug: ca_file = "/etc/freeradius/certs/ca.pem"
Fri Feb 26 09:09:12 2016 : Debug: private_key_password = "whatever"
Fri Feb 26 09:09:12 2016 : Debug: dh_file = "/etc/freeradius/certs/dh"
Fri Feb 26 09:09:12 2016 : Debug: fragment_size = 1024
Fri Feb 26 09:09:12 2016 : Debug: include_length = yes
Fri Feb 26 09:09:12 2016 : Debug: check_crl = no
Fri Feb 26 09:09:12 2016 : Debug: check_all_crl = no
Fri Feb 26 09:09:12 2016 : Debug: cipher_list = "DEFAULT"
Fri Feb 26 09:09:12 2016 : Debug: ecdh_curve = "prime256v1"
Fri Feb 26 09:09:12 2016 : Debug: cache {
Fri Feb 26 09:09:12 2016 : Debug: enable = yes
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 24
Fri Feb 26 09:09:12 2016 : Debug: max_entries = 255
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: verify {
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: ocsp {
Fri Feb 26 09:09:12 2016 : Debug: enable = no
Fri Feb 26 09:09:12 2016 : Debug: override_cert_url = yes
Fri Feb 26 09:09:12 2016 : Debug: url = "http://127.0.0.1/ocsp/"
Fri Feb 26 09:09:12 2016 : Debug: use_nonce = yes
Fri Feb 26 09:09:12 2016 : Debug: timeout = 0
Fri Feb 26 09:09:12 2016 : Debug: softfail = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_ttls.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_ttls
Fri Feb 26 09:09:12 2016 : Debug: ttls {
Fri Feb 26 09:09:12 2016 : Debug: tls = "tls-common"
Fri Feb 26 09:09:12 2016 : Debug: default_eap_type = "md5"
Fri Feb 26 09:09:12 2016 : Debug: copy_request_to_tunnel = no
Fri Feb 26 09:09:12 2016 : Debug: use_tunneled_reply = yes
Fri Feb 26 09:09:12 2016 : Debug: virtual_server = "inner-tunnel"
Fri Feb 26 09:09:12 2016 : Debug: include_length = yes
Fri Feb 26 09:09:12 2016 : Debug: require_client_cert = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: tls: Using cached TLS configuration from previous invocation
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_peap.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_peap
Fri Feb 26 09:09:12 2016 : Debug: peap {
Fri Feb 26 09:09:12 2016 : Debug: tls = "tls-common"
Fri Feb 26 09:09:12 2016 : Debug: default_eap_type = "mschapv2"
Fri Feb 26 09:09:12 2016 : Debug: copy_request_to_tunnel = yes
Fri Feb 26 09:09:12 2016 : Debug: use_tunneled_reply = yes
Fri Feb 26 09:09:12 2016 : Debug: proxy_tunneled_request_as_eap = yes
Fri Feb 26 09:09:12 2016 : Debug: virtual_server = "inner-tunnel"
Fri Feb 26 09:09:12 2016 : Debug: soh = no
Fri Feb 26 09:09:12 2016 : Debug: require_client_cert = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: tls: Using cached TLS configuration from previous invocation
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/rlm_eap_mschapv2.so"
Fri Feb 26 09:09:12 2016 : Debug: # Linked to sub-module rlm_eap_mschapv2
Fri Feb 26 09:09:12 2016 : Debug: mschapv2 {
Fri Feb 26 09:09:12 2016 : Debug: with_ntdomain_hack = no
Fri Feb 26 09:09:12 2016 : Debug: send_error = no
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "pap" from file /etc/freeradius/mods-enabled/pap
Fri Feb 26 09:09:12 2016 : Debug: # Instantiating module "expiration" from file /etc/freeradius/mods-enabled/expiration
Fri Feb 26 09:09:12 2016 : Debug: } # modules
Fri Feb 26 09:09:12 2016 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Feb 26 09:09:12 2016 : Debug: server { # from file /etc/freeradius/radiusd.conf
Fri Feb 26 09:09:12 2016 : Debug: } # server
Fri Feb 26 09:09:12 2016 : Debug: server default { # from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:12 2016 : Debug: authenticate {
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: pap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: chap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: mschap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: digest
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: } # authenticate
Fri Feb 26 09:09:12 2016 : Debug: authorize {
Fri Feb 26 09:09:12 2016 : Debug: preprocess
Fri Feb 26 09:09:12 2016 : Debug: chap
Fri Feb 26 09:09:12 2016 : Debug: mschap
Fri Feb 26 09:09:12 2016 : Debug: digest
Fri Feb 26 09:09:12 2016 : Debug: suffix
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Warning: Ignoring "ldap" (see raddb/mods-available/README.rst)
Fri Feb 26 09:09:12 2016 : Debug: expiration
Fri Feb 26 09:09:12 2016 : Debug: logintime
Fri Feb 26 09:09:12 2016 : Debug: pap
Fri Feb 26 09:09:12 2016 : Debug: } # authorize
Fri Feb 26 09:09:12 2016 : Debug: preacct {
Fri Feb 26 09:09:12 2016 : Debug: preprocess
Fri Feb 26 09:09:12 2016 : Debug: policy acct_unique {
Fri Feb 26 09:09:12 2016 : Debug: if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/) {
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 2016 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: else {
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 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}}"
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: suffix
Fri Feb 26 09:09:12 2016 : Debug: } # preacct
Fri Feb 26 09:09:12 2016 : Debug: accounting {
Fri Feb 26 09:09:12 2016 : Debug: detail
Fri Feb 26 09:09:12 2016 : Debug: unix
Fri Feb 26 09:09:12 2016 : Debug: radutmp
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: exec
Fri Feb 26 09:09:12 2016 : Debug: attr_filter.accounting_response
Fri Feb 26 09:09:12 2016 : Debug: } # accounting
Fri Feb 26 09:09:12 2016 : Debug: session {
Fri Feb 26 09:09:12 2016 : Debug: radutmp
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: } # session
Fri Feb 26 09:09:12 2016 : Debug: post-proxy {
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: } # post-proxy
Fri Feb 26 09:09:12 2016 : Debug: post-auth {
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 2016 : Debug: &reply[*] += &session-state[*]
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: exec
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: attr_filter.access_reject
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: policy remove_reply_message_if_eap {
Fri Feb 26 09:09:12 2016 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) {
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 2016 : Debug: &reply:Reply-Message !* ANY
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: else {
Fri Feb 26 09:09:12 2016 : Debug: noop
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: } # post-auth
Fri Feb 26 09:09:12 2016 : Debug: } # server default
Fri Feb 26 09:09:12 2016 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel
Fri Feb 26 09:09:12 2016 : Debug: authenticate {
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: pap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: chap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: mschap
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: } # authenticate
Fri Feb 26 09:09:12 2016 : Debug: authorize {
Fri Feb 26 09:09:12 2016 : Debug: chap
Fri Feb 26 09:09:12 2016 : Debug: mschap
Fri Feb 26 09:09:12 2016 : Debug: suffix
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 2016 : Debug: &control:Proxy-To-Realm := LOCAL
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: expiration
Fri Feb 26 09:09:12 2016 : Debug: logintime
Fri Feb 26 09:09:12 2016 : Debug: pap
Fri Feb 26 09:09:12 2016 : Debug: } # authorize
Fri Feb 26 09:09:12 2016 : Debug: session {
Fri Feb 26 09:09:12 2016 : Debug: radutmp
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: } # session
Fri Feb 26 09:09:12 2016 : Debug: post-proxy {
Fri Feb 26 09:09:12 2016 : Debug: eap
Fri Feb 26 09:09:12 2016 : Debug: } # post-proxy
Fri Feb 26 09:09:12 2016 : Debug: post-auth {
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: group {
Fri Feb 26 09:09:12 2016 : Debug: sql
Fri Feb 26 09:09:12 2016 : Debug: attr_filter.access_reject
Fri Feb 26 09:09:12 2016 : Debug: update {
Fri Feb 26 09:09:12 2016 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: } # post-auth
Fri Feb 26 09:09:12 2016 : Debug: } # server inner-tunnel
Fri Feb 26 09:09:12 2016 : Debug: Created signal pipe. Read end FD 11, write end FD 12
Fri Feb 26 09:09:12 2016 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/proto_auth.so"
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: Library file not found
Fri Feb 26 09:09:12 2016 : Debug: Loading library using linker search path(s)
Fri Feb 26 09:09:12 2016 : Debug: Defaults : /lib:/usr/lib
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: listen {
Fri Feb 26 09:09:12 2016 : Debug: type = "auth"
Fri Feb 26 09:09:12 2016 : Debug: ipaddr = *
Fri Feb 26 09:09:12 2016 : Debug: port = 0
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/proto_acct.so"
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: Library file not found
Fri Feb 26 09:09:12 2016 : Debug: Loading library using linker search path(s)
Fri Feb 26 09:09:12 2016 : Debug: Defaults : /lib:/usr/lib
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: listen {
Fri Feb 26 09:09:12 2016 : Debug: type = "acct"
Fri Feb 26 09:09:12 2016 : Debug: ipaddr = *
Fri Feb 26 09:09:12 2016 : Debug: port = 0
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/proto_auth.so"
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: Library file not found
Fri Feb 26 09:09:12 2016 : Debug: Loading library using linker search path(s)
Fri Feb 26 09:09:12 2016 : Debug: Defaults : /lib:/usr/lib
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: listen {
Fri Feb 26 09:09:12 2016 : Debug: type = "auth"
Fri Feb 26 09:09:12 2016 : Debug: ipv6addr = ::
Fri Feb 26 09:09:12 2016 : Debug: port = 0
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/proto_acct.so"
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: Library file not found
Fri Feb 26 09:09:12 2016 : Debug: Loading library using linker search path(s)
Fri Feb 26 09:09:12 2016 : Debug: Defaults : /lib:/usr/lib
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: listen {
Fri Feb 26 09:09:12 2016 : Debug: type = "acct"
Fri Feb 26 09:09:12 2016 : Debug: ipv6addr = ::
Fri Feb 26 09:09:12 2016 : Debug: port = 0
Fri Feb 26 09:09:12 2016 : Debug: limit {
Fri Feb 26 09:09:12 2016 : Debug: max_connections = 16
Fri Feb 26 09:09:12 2016 : Debug: lifetime = 0
Fri Feb 26 09:09:12 2016 : Debug: idle_timeout = 30
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Loading library using absolute path "/usr/lib/freeradius/proto_auth.so"
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: Library file not found
Fri Feb 26 09:09:12 2016 : Debug: Loading library using linker search path(s)
Fri Feb 26 09:09:12 2016 : Debug: Defaults : /lib:/usr/lib
Fri Feb 26 09:09:12 2016 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory
Fri Feb 26 09:09:12 2016 : Debug: listen {
Fri Feb 26 09:09:12 2016 : Debug: type = "auth"
Fri Feb 26 09:09:12 2016 : Debug: ipaddr = 127.0.0.1
Fri Feb 26 09:09:12 2016 : Debug: port = 18120
Fri Feb 26 09:09:12 2016 : Debug: }
Fri Feb 26 09:09:12 2016 : Debug: Listening on auth address * port 1812 bound to server default
Fri Feb 26 09:09:12 2016 : Debug: Listening on acct address * port 1813 bound to server default
Fri Feb 26 09:09:12 2016 : Debug: Listening on auth address :: port 1812 bound to server default
Fri Feb 26 09:09:12 2016 : Debug: Listening on acct address :: port 1813 bound to server default
Fri Feb 26 09:09:12 2016 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel
Fri Feb 26 09:09:12 2016 : Debug: Opened new proxy socket 'proxy address * port 52333'
Fri Feb 26 09:09:12 2016 : Debug: Listening on proxy address * port 52333
Fri Feb 26 09:09:12 2016 : Debug: Opened new proxy socket 'proxy address :: port 52096'
Fri Feb 26 09:09:12 2016 : Debug: Listening on proxy address :: port 52096
Fri Feb 26 09:09:12 2016 : Info: Ready to process requests
Fri Feb 26 09:09:20 2016 : Debug: (0) Received Access-Request Id 94 from 192.168.6.211:1812 to 192.168.1.65:1812 length 116
Fri Feb 26 09:09:20 2016 : Debug: (0) User-Name = "test"
Fri Feb 26 09:09:20 2016 : Debug: (0) NAS-IP-Address = 211.6.168.192
Fri Feb 26 09:09:20 2016 : Debug: (0) NAS-Identifier = "SWITCH01-TEST"
Fri Feb 26 09:09:20 2016 : Debug: (0) NAS-Port-Type = Virtual
Fri Feb 26 09:09:20 2016 : Debug: (0) Service-Type = NAS-Prompt-User
Fri Feb 26 09:09:20 2016 : Debug: (0) EAP-Message = 0x020000090174657374
Fri Feb 26 09:09:20 2016 : Debug: (0) Message-Authenticator = 0xad23178550d4d9d40cd4ea363c3c6eef
Fri Feb 26 09:09:20 2016 : Debug: (0) MS-RAS-Vendor = 184549376
Fri Feb 26 09:09:20 2016 : Debug: (0) Calling-Station-Id = "192.168.14.114"
Fri Feb 26 09:09:20 2016 : Debug: (0) session-state: No State attribute
Fri Feb 26 09:09:20 2016 : Debug: (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (0) authorize {
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [preprocess] = ok
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [chap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [mschap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [digest] = noop
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) suffix: Checking for suffix after "@"
Fri Feb 26 09:09:20 2016 : Debug: (0) suffix: No '@' in User-Name = "test", looking up realm NULL
Fri Feb 26 09:09:20 2016 : Debug: (0) suffix: No such realm "NULL"
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [suffix] = noop
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: Peer sent EAP Response (code 2) ID 0 length 9
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [eap] = ok
Fri Feb 26 09:09:20 2016 : Debug: (0) } # authorize = ok
Fri Feb 26 09:09:20 2016 : Debug: (0) Found Auth-Type = EAP
Fri Feb 26 09:09:20 2016 : Debug: (0) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (0) authenticate {
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: Peer sent packet with method EAP Identity (1)
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: Calling submodule eap_md5 to process data
Fri Feb 26 09:09:20 2016 : Debug: (0) eap_md5: Issuing MD5 Challenge
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: Sending EAP Request (code 1) ID 1 length 22
Fri Feb 26 09:09:20 2016 : Debug: (0) eap: EAP session adding &reply:State = 0x49d1e9bb49d0ed66
Fri Feb 26 09:09:20 2016 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Fri Feb 26 09:09:20 2016 : Debug: (0) [eap] = handled
Fri Feb 26 09:09:20 2016 : Debug: (0) } # authenticate = handled
Fri Feb 26 09:09:20 2016 : Debug: (0) Using Post-Auth-Type Challenge
Fri Feb 26 09:09:20 2016 : Debug: (0) Post-Auth-Type sub-section not found. Ignoring.
Fri Feb 26 09:09:20 2016 : Debug: (0) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (0) session-state: Nothing to cache
Fri Feb 26 09:09:20 2016 : Debug: (0) Sent Access-Challenge Id 94 from 192.168.1.65:1812 to 192.168.6.211:1812 length 0
Fri Feb 26 09:09:20 2016 : Debug: (0) EAP-Message = 0x010100160410cf9fddc333bc02de4f7986fbf39093f9
Fri Feb 26 09:09:20 2016 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000
Fri Feb 26 09:09:20 2016 : Debug: (0) State = 0x49d1e9bb49d0ed6604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (0) Finished request
Fri Feb 26 09:09:20 2016 : Debug: Waking up in 4.9 seconds.
Fri Feb 26 09:09:20 2016 : Debug: (1) Received Access-Request Id 95 from 192.168.6.211:1812 to 192.168.1.65:1812 length 131
Fri Feb 26 09:09:20 2016 : Debug: (1) User-Name = "test"
Fri Feb 26 09:09:20 2016 : Debug: (1) NAS-IP-Address = 211.6.168.192
Fri Feb 26 09:09:20 2016 : Debug: (1) NAS-Identifier = "SWITCH01-TEST"
Fri Feb 26 09:09:20 2016 : Debug: (1) NAS-Port-Type = Virtual
Fri Feb 26 09:09:20 2016 : Debug: (1) Service-Type = NAS-Prompt-User
Fri Feb 26 09:09:20 2016 : Debug: (1) State = 0x49d1e9bb49d0ed6604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (1) EAP-Message = 0x020100060319
Fri Feb 26 09:09:20 2016 : Debug: (1) Message-Authenticator = 0xc3f34c4d541be70e121ca7c8c01784c1
Fri Feb 26 09:09:20 2016 : Debug: (1) MS-RAS-Vendor = 184549376
Fri Feb 26 09:09:20 2016 : Debug: (1) Calling-Station-Id = "192.168.14.114"
Fri Feb 26 09:09:20 2016 : Debug: (1) session-state: No cached attributes
Fri Feb 26 09:09:20 2016 : Debug: (1) # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (1) authorize {
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [preprocess] = ok
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling chap (rlm_chap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from chap (rlm_chap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [chap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling mschap (rlm_mschap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from mschap (rlm_mschap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [mschap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling digest (rlm_digest) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from digest (rlm_digest) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [digest] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling suffix (rlm_realm) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) suffix: Checking for suffix after "@"
Fri Feb 26 09:09:20 2016 : Debug: (1) suffix: No '@' in User-Name = "test", looking up realm NULL
Fri Feb 26 09:09:20 2016 : Debug: (1) suffix: No such realm "NULL"
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [suffix] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Peer sent EAP Response (code 2) ID 1 length 6
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: No EAP Start, assuming it's an on-going EAP conversation
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [eap] = updated
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling sql (rlm_sql) for request 1
Fri Feb 26 09:09:20 2016 : Debug: %{User-Name}
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: attribute --> User-Name
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND %{User-Name}
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> test
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: SQL-User-Name set to 'test'
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: FROM 1 TO 12 MAX 13
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: Examining SQL-User-Name
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: APPENDING SQL-User-Name FROM 0 TO 12
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: TO in 12 out 12
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[0] = User-Name
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[1] = NAS-IP-Address
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[2] = NAS-Identifier
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[3] = NAS-Port-Type
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[4] = Service-Type
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[5] = State
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[6] = EAP-Message
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[7] = Message-Authenticator
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[8] = MS-RAS-Vendor
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[9] = Calling-Station-Id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[10] = Event-Timestamp
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[11] = EAP-Type
Fri Feb 26 09:09:20 2016 : Debug: rlm_sql (sql): Reserved connection (1)
Fri Feb 26 09:09:20 2016 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '
Fri Feb 26 09:09:20 2016 : Debug: attribute --> SQL-User-Name
Fri Feb 26 09:09:20 2016 : Debug: literal --> ' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'test' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'test' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: User found in radcheck table
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Conditional check items matched, merging assignment check items
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Cleartext-Password := "test"
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: FROM 1 TO 1 MAX 2
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: Examining Cleartext-Password
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: APPENDING Cleartext-Password FROM 0 TO 1
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: TO in 1 out 1
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[0] = Auth-Type
Fri Feb 26 09:09:20 2016 : Debug: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: literal --> SELECT id, username, attribute, value, op FROM radreply WHERE username = '
Fri Feb 26 09:09:20 2016 : Debug: attribute --> SQL-User-Name
Fri Feb 26 09:09:20 2016 : Debug: literal --> ' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'test' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'test' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ... falling-through to group processing
Fri Feb 26 09:09:20 2016 : Debug: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = '
Fri Feb 26 09:09:20 2016 : Debug: attribute --> SQL-User-Name
Fri Feb 26 09:09:20 2016 : Debug: literal --> ' ORDER BY priority
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: User found in the group table
Fri Feb 26 09:09:20 2016 : Debug: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: literal --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '
Fri Feb 26 09:09:20 2016 : Debug: attribute --> SQL-Group
Fri Feb 26 09:09:20 2016 : Debug: literal --> ' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Switch' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'HP-Procurve-Switch' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Group "HP-Procurve-Switch": Conditional check items matched
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Group "HP-Procurve-Switch": Merging assignment check items
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: FROM 0 TO 2 MAX 2
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: TO in 2 out 2
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[0] = Auth-Type
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: to[1] = Cleartext-Password
Fri Feb 26 09:09:20 2016 : Debug: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: Parsed xlat tree:
Fri Feb 26 09:09:20 2016 : Debug: literal --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '
Fri Feb 26 09:09:20 2016 : Debug: attribute --> SQL-Group
Fri Feb 26 09:09:20 2016 : Debug: literal --> ' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Switch' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'HP-Procurve-Switch' ORDER BY id
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Group "HP-Procurve-Switch": Merging reply items
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: Service-Type = Administrative-User
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: FROM 1 TO 0 MAX 1
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: Examining Service-Type
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: APPENDING Service-Type FROM 0 TO 0
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ::: TO in 0 out 0
Fri Feb 26 09:09:20 2016 : Debug: (1) sql: ... falling-through to profile processing
Fri Feb 26 09:09:20 2016 : Debug: rlm_sql (sql): Released connection (1)
Fri Feb 26 09:09:20 2016 : Info: rlm_sql (sql): Need 4 more connections to reach 10 spares
Fri Feb 26 09:09:20 2016 : Info: rlm_sql (sql): Opening additional connection (6), 1 of 26 pending slots used
Fri Feb 26 09:09:20 2016 : Debug: rlm_sql_mysql: Starting connect to MySQL server
Fri Feb 26 09:09:20 2016 : Debug: rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.5.47-0ubuntu0.14.04.1, protocol version 10
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from sql (rlm_sql) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [sql] = ok
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling expiration (rlm_expiration) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from expiration (rlm_expiration) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [expiration] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling logintime (rlm_logintime) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from logintime (rlm_logintime) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [logintime] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: calling pap (rlm_pap) for request 1
Fri Feb 26 09:09:20 2016 : WARNING: (1) pap: Auth-Type already set. Not setting to PAP
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authorize]: returned from pap (rlm_pap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [pap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (1) } # authorize = updated
Fri Feb 26 09:09:20 2016 : Debug: (1) Found Auth-Type = EAP
Fri Feb 26 09:09:20 2016 : Debug: (1) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (1) authenticate {
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Expiring EAP session with state 0x49d1e9bb49d0ed66
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Finished EAP session with state 0x49d1e9bb49d0ed66
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Previous EAP request found for state 0x49d1e9bb49d0ed66, released from the list
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Peer sent packet with method EAP NAK (3)
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Found mutually acceptable type PEAP (25)
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Calling submodule eap_peap to process data
Fri Feb 26 09:09:20 2016 : Debug: (1) eap_peap: Initiating new EAP-TLS session
Fri Feb 26 09:09:20 2016 : Debug: (1) eap_peap: Flushing SSL sessions (of #0)
Fri Feb 26 09:09:20 2016 : Debug: (1) eap_peap: [eaptls start] = request
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: Sending EAP Request (code 1) ID 2 length 6
Fri Feb 26 09:09:20 2016 : Debug: (1) eap: EAP session adding &reply:State = 0x49d1e9bb48d3f066
Fri Feb 26 09:09:20 2016 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap) for request 1
Fri Feb 26 09:09:20 2016 : Debug: (1) [eap] = handled
Fri Feb 26 09:09:20 2016 : Debug: (1) } # authenticate = handled
Fri Feb 26 09:09:20 2016 : Debug: (1) Using Post-Auth-Type Challenge
Fri Feb 26 09:09:20 2016 : Debug: (1) Post-Auth-Type sub-section not found. Ignoring.
Fri Feb 26 09:09:20 2016 : Debug: (1) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (1) session-state: Nothing to cache
Fri Feb 26 09:09:20 2016 : Debug: (1) Sent Access-Challenge Id 95 from 192.168.1.65:1812 to 192.168.6.211:1812 length 0
Fri Feb 26 09:09:20 2016 : Debug: (1) Service-Type = Administrative-User
Fri Feb 26 09:09:20 2016 : Debug: (1) EAP-Message = 0x010200061920
Fri Feb 26 09:09:20 2016 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000
Fri Feb 26 09:09:20 2016 : Debug: (1) State = 0x49d1e9bb48d3f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (1) Finished request
Fri Feb 26 09:09:20 2016 : Debug: Waking up in 4.9 seconds.
Fri Feb 26 09:09:20 2016 : Debug: (2) Received Access-Request Id 96 from 192.168.6.211:1812 to 192.168.1.65:1812 length 211
Fri Feb 26 09:09:20 2016 : Debug: (2) User-Name = "test"
Fri Feb 26 09:09:20 2016 : Debug: (2) NAS-IP-Address = 211.6.168.192
Fri Feb 26 09:09:20 2016 : Debug: (2) NAS-Identifier = "SWITCH01-TEST"
Fri Feb 26 09:09:20 2016 : Debug: (2) NAS-Port-Type = Virtual
Fri Feb 26 09:09:20 2016 : Debug: (2) Service-Type = NAS-Prompt-User
Fri Feb 26 09:09:20 2016 : Debug: (2) State = 0x49d1e9bb48d3f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (2) EAP-Message = 0x020200561900160303004b010000470303f469e888bc5f0be285d0034944e649c51126cce388e1c602d6e68b3d32077ec600000c003d0035003c002f000a000901000012000d000e000c060105010401030102010101
Fri Feb 26 09:09:20 2016 : Debug: (2) Message-Authenticator = 0x2ce1bdbb10507e63da3523deaea3b9ac
Fri Feb 26 09:09:20 2016 : Debug: (2) MS-RAS-Vendor = 184549376
Fri Feb 26 09:09:20 2016 : Debug: (2) Calling-Station-Id = "192.168.14.114"
Fri Feb 26 09:09:20 2016 : Debug: (2) session-state: No cached attributes
Fri Feb 26 09:09:20 2016 : Debug: (2) # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (2) authorize {
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [preprocess] = ok
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling chap (rlm_chap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from chap (rlm_chap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [chap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling mschap (rlm_mschap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from mschap (rlm_mschap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [mschap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling digest (rlm_digest) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from digest (rlm_digest) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [digest] = noop
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling suffix (rlm_realm) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) suffix: Checking for suffix after "@"
Fri Feb 26 09:09:20 2016 : Debug: (2) suffix: No '@' in User-Name = "test", looking up realm NULL
Fri Feb 26 09:09:20 2016 : Debug: (2) suffix: No such realm "NULL"
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from suffix (rlm_realm) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [suffix] = noop
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 2 length 86
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Continuing tunnel setup
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [eap] = ok
Fri Feb 26 09:09:20 2016 : Debug: (2) } # authorize = ok
Fri Feb 26 09:09:20 2016 : Debug: (2) Found Auth-Type = EAP
Fri Feb 26 09:09:20 2016 : Debug: (2) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (2) authenticate {
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Expiring EAP session with state 0x49d1e9bb48d3f066
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Finished EAP session with state 0x49d1e9bb48d3f066
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Previous EAP request found for state 0x49d1e9bb48d3f066, released from the list
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Peer sent packet with method EAP PEAP (25)
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Calling submodule eap_peap to process data
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: Continuing EAP-TLS
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: Peer sent flags ---
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: [eaptls verify] = ok
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: Done initial handshake
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: (other): before/accept initialization
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: before/accept initialization
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: <<< TLS 1.2 [length 004b]
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: SSLv3 read client hello A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: >>> TLS 1.2 [length 004a]
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: SSLv3 write server hello A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: >>> TLS 1.2 [length 08d3]
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: SSLv3 write certificate A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: >>> TLS 1.2 [length 0004]
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: SSLv3 write server done A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: SSLv3 flush data
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: TLS_accept: Need to read more data: SSLv3 read client certificate A
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: In SSL Handshake Phase
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: In SSL Accept mode
Fri Feb 26 09:09:20 2016 : Debug: (2) eap_peap: [eaptls process] = handled
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: Sending EAP Request (code 1) ID 3 length 1004
Fri Feb 26 09:09:20 2016 : Debug: (2) eap: EAP session adding &reply:State = 0x49d1e9bb4bd2f066
Fri Feb 26 09:09:20 2016 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) for request 2
Fri Feb 26 09:09:20 2016 : Debug: (2) [eap] = handled
Fri Feb 26 09:09:20 2016 : Debug: (2) } # authenticate = handled
Fri Feb 26 09:09:20 2016 : Debug: (2) Using Post-Auth-Type Challenge
Fri Feb 26 09:09:20 2016 : Debug: (2) Post-Auth-Type sub-section not found. Ignoring.
Fri Feb 26 09:09:20 2016 : Debug: (2) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (2) session-state: Nothing to cache
Fri Feb 26 09:09:20 2016 : Debug: (2) Sent Access-Challenge Id 96 from 192.168.1.65:1812 to 192.168.6.211:1812 length 0
Fri Feb 26 09:09:20 2016 : Debug: (2) EAP-Message = 0x010303ec19c000000930160303004a02000046030354fe36731b467feb5884257e28f240b1ec929d24c9e32152f69a15b29383707a200887f19083730e7634c25242b95cf3766946898850934650cbef5fdc96063735003d0016030308d30b0008cf0008cc0003de308203da308202c2a0030201020201
Fri Feb 26 09:09:20 2016 : Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000
Fri Feb 26 09:09:20 2016 : Debug: (2) State = 0x49d1e9bb4bd2f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (2) Finished request
Fri Feb 26 09:09:20 2016 : Debug: Waking up in 4.9 seconds.
Fri Feb 26 09:09:20 2016 : Debug: (3) Received Access-Request Id 97 from 192.168.6.211:1812 to 192.168.1.65:1812 length 131
Fri Feb 26 09:09:20 2016 : Debug: (3) User-Name = "test"
Fri Feb 26 09:09:20 2016 : Debug: (3) NAS-IP-Address = 211.6.168.192
Fri Feb 26 09:09:20 2016 : Debug: (3) NAS-Identifier = "SWITCH01-TEST"
Fri Feb 26 09:09:20 2016 : Debug: (3) NAS-Port-Type = Virtual
Fri Feb 26 09:09:20 2016 : Debug: (3) Service-Type = NAS-Prompt-User
Fri Feb 26 09:09:20 2016 : Debug: (3) State = 0x49d1e9bb4bd2f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (3) EAP-Message = 0x020300061900
Fri Feb 26 09:09:20 2016 : Debug: (3) Message-Authenticator = 0x0b12f8d3e8972bbd6ac1b77f1e73f4da
Fri Feb 26 09:09:20 2016 : Debug: (3) MS-RAS-Vendor = 184549376
Fri Feb 26 09:09:20 2016 : Debug: (3) Calling-Station-Id = "192.168.14.114"
Fri Feb 26 09:09:20 2016 : Debug: (3) session-state: No cached attributes
Fri Feb 26 09:09:20 2016 : Debug: (3) # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (3) authorize {
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [preprocess] = ok
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling chap (rlm_chap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from chap (rlm_chap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [chap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling mschap (rlm_mschap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from mschap (rlm_mschap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [mschap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling digest (rlm_digest) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from digest (rlm_digest) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [digest] = noop
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling suffix (rlm_realm) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) suffix: Checking for suffix after "@"
Fri Feb 26 09:09:20 2016 : Debug: (3) suffix: No '@' in User-Name = "test", looking up realm NULL
Fri Feb 26 09:09:20 2016 : Debug: (3) suffix: No such realm "NULL"
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from suffix (rlm_realm) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [suffix] = noop
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Peer sent EAP Response (code 2) ID 3 length 6
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Continuing tunnel setup
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [eap] = ok
Fri Feb 26 09:09:20 2016 : Debug: (3) } # authorize = ok
Fri Feb 26 09:09:20 2016 : Debug: (3) Found Auth-Type = EAP
Fri Feb 26 09:09:20 2016 : Debug: (3) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (3) authenticate {
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Expiring EAP session with state 0x49d1e9bb4bd2f066
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Finished EAP session with state 0x49d1e9bb4bd2f066
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Previous EAP request found for state 0x49d1e9bb4bd2f066, released from the list
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Peer sent packet with method EAP PEAP (25)
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Calling submodule eap_peap to process data
Fri Feb 26 09:09:20 2016 : Debug: (3) eap_peap: Continuing EAP-TLS
Fri Feb 26 09:09:20 2016 : Debug: (3) eap_peap: Peer sent flags ---
Fri Feb 26 09:09:20 2016 : Debug: (3) eap_peap: Peer ACKed our handshake fragment
Fri Feb 26 09:09:20 2016 : Debug: (3) eap_peap: [eaptls verify] = request
Fri Feb 26 09:09:20 2016 : Debug: (3) eap_peap: [eaptls process] = handled
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: Sending EAP Request (code 1) ID 4 length 1000
Fri Feb 26 09:09:20 2016 : Debug: (3) eap: EAP session adding &reply:State = 0x49d1e9bb4ad5f066
Fri Feb 26 09:09:20 2016 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) for request 3
Fri Feb 26 09:09:20 2016 : Debug: (3) [eap] = handled
Fri Feb 26 09:09:20 2016 : Debug: (3) } # authenticate = handled
Fri Feb 26 09:09:20 2016 : Debug: (3) Using Post-Auth-Type Challenge
Fri Feb 26 09:09:20 2016 : Debug: (3) Post-Auth-Type sub-section not found. Ignoring.
Fri Feb 26 09:09:20 2016 : Debug: (3) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (3) session-state: Nothing to cache
Fri Feb 26 09:09:20 2016 : Debug: (3) Sent Access-Challenge Id 97 from 192.168.1.65:1812 to 192.168.6.211:1812 length 0
Fri Feb 26 09:09:20 2016 : Debug: (3) EAP-Message = 0x010403e8194037f46e0cd6a1c7903aa76984aa8740c82df8d7e54ac0028e4acb7016fb031b9e8d801916efbc80b0502432c9edfe776560ac6860c8c92f7dcc0602db1761dd3cdeedc764a04c9323ec69c92a4cae841cb61bfcde2132df31e7d70004e8308204e4308203cca0030201020209008811b646
Fri Feb 26 09:09:20 2016 : Debug: (3) Message-Authenticator = 0x00000000000000000000000000000000
Fri Feb 26 09:09:20 2016 : Debug: (3) State = 0x49d1e9bb4ad5f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (3) Finished request
Fri Feb 26 09:09:20 2016 : Debug: Waking up in 4.9 seconds.
Fri Feb 26 09:09:20 2016 : Debug: (4) Received Access-Request Id 98 from 192.168.6.211:1812 to 192.168.1.65:1812 length 131
Fri Feb 26 09:09:20 2016 : Debug: (4) User-Name = "test"
Fri Feb 26 09:09:20 2016 : Debug: (4) NAS-IP-Address = 211.6.168.192
Fri Feb 26 09:09:20 2016 : Debug: (4) NAS-Identifier = "SWITCH01-TEST"
Fri Feb 26 09:09:20 2016 : Debug: (4) NAS-Port-Type = Virtual
Fri Feb 26 09:09:20 2016 : Debug: (4) Service-Type = NAS-Prompt-User
Fri Feb 26 09:09:20 2016 : Debug: (4) State = 0x49d1e9bb4ad5f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (4) EAP-Message = 0x020400061900
Fri Feb 26 09:09:20 2016 : Debug: (4) Message-Authenticator = 0x2b99fbc2e77e6ad0efb2e85b90a62f18
Fri Feb 26 09:09:20 2016 : Debug: (4) MS-RAS-Vendor = 184549376
Fri Feb 26 09:09:20 2016 : Debug: (4) Calling-Station-Id = "192.168.14.114"
Fri Feb 26 09:09:20 2016 : Debug: (4) session-state: No cached attributes
Fri Feb 26 09:09:20 2016 : Debug: (4) # Executing section authorize from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (4) authorize {
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [preprocess] = ok
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling chap (rlm_chap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from chap (rlm_chap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [chap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling mschap (rlm_mschap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from mschap (rlm_mschap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [mschap] = noop
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling digest (rlm_digest) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from digest (rlm_digest) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [digest] = noop
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling suffix (rlm_realm) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) suffix: Checking for suffix after "@"
Fri Feb 26 09:09:20 2016 : Debug: (4) suffix: No '@' in User-Name = "test", looking up realm NULL
Fri Feb 26 09:09:20 2016 : Debug: (4) suffix: No such realm "NULL"
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from suffix (rlm_realm) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [suffix] = noop
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Peer sent EAP Response (code 2) ID 4 length 6
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Continuing tunnel setup
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [eap] = ok
Fri Feb 26 09:09:20 2016 : Debug: (4) } # authorize = ok
Fri Feb 26 09:09:20 2016 : Debug: (4) Found Auth-Type = EAP
Fri Feb 26 09:09:20 2016 : Debug: (4) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (4) authenticate {
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Expiring EAP session with state 0x49d1e9bb4ad5f066
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Finished EAP session with state 0x49d1e9bb4ad5f066
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Previous EAP request found for state 0x49d1e9bb4ad5f066, released from the list
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Peer sent packet with method EAP PEAP (25)
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Calling submodule eap_peap to process data
Fri Feb 26 09:09:20 2016 : Debug: (4) eap_peap: Continuing EAP-TLS
Fri Feb 26 09:09:20 2016 : Debug: (4) eap_peap: Peer sent flags ---
Fri Feb 26 09:09:20 2016 : Debug: (4) eap_peap: Peer ACKed our handshake fragment
Fri Feb 26 09:09:20 2016 : Debug: (4) eap_peap: [eaptls verify] = request
Fri Feb 26 09:09:20 2016 : Debug: (4) eap_peap: [eaptls process] = handled
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: Sending EAP Request (code 1) ID 5 length 370
Fri Feb 26 09:09:20 2016 : Debug: (4) eap: EAP session adding &reply:State = 0x49d1e9bb4dd4f066
Fri Feb 26 09:09:20 2016 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) for request 4
Fri Feb 26 09:09:20 2016 : Debug: (4) [eap] = handled
Fri Feb 26 09:09:20 2016 : Debug: (4) } # authenticate = handled
Fri Feb 26 09:09:20 2016 : Debug: (4) Using Post-Auth-Type Challenge
Fri Feb 26 09:09:20 2016 : Debug: (4) Post-Auth-Type sub-section not found. Ignoring.
Fri Feb 26 09:09:20 2016 : Debug: (4) # Executing group from file /etc/freeradius/sites-enabled/default
Fri Feb 26 09:09:20 2016 : Debug: (4) session-state: Nothing to cache
Fri Feb 26 09:09:20 2016 : Debug: (4) Sent Access-Challenge Id 98 from 192.168.1.65:1812 to 192.168.6.211:1812 length 0
Fri Feb 26 09:09:20 2016 : Debug: (4) EAP-Message = 0x010501721900b646e6d0eb27300f0603551d130101ff040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e6f72672f6578616d706c655f63612e63726c300d06092a864886f70d01010b050003820101004e489dea74691aee9abfa8bd8500
Fri Feb 26 09:09:20 2016 : Debug: (4) Message-Authenticator = 0x00000000000000000000000000000000
Fri Feb 26 09:09:20 2016 : Debug: (4) State = 0x49d1e9bb4dd4f06604270874f25476f7
Fri Feb 26 09:09:20 2016 : Debug: (4) Finished request
Fri Feb 26 09:09:20 2016 : Debug: Waking up in 4.9 seconds.
Fri Feb 26 09:09:25 2016 : Debug: (0) Cleaning up request packet ID 94 with timestamp +8
Fri Feb 26 09:09:25 2016 : Debug: (1) Cleaning up request packet ID 95 with timestamp +8
Fri Feb 26 09:09:25 2016 : Debug: (2) Cleaning up request packet ID 96 with timestamp +8
Fri Feb 26 09:09:25 2016 : Debug: (3) Cleaning up request packet ID 97 with timestamp +8
Fri Feb 26 09:09:25 2016 : Debug: (4) Cleaning up request packet ID 98 with timestamp +8
Fri Feb 26 09:09:25 2016 : Info: Ready to process requests
Can anyone help me?
Best regards
jonas
3
15
Thanks Alan
One small further question if I may. FR (using freetds) is currently
set against a single mssql server. We are currently setting a second
SQL server to allow failover in the case of a server failure. I assume
we can run two freetds modules to allow freeradius to failover OK ?
I shall be building a test server here the next few days. Should I
take the latest .tar from the website or download from git ?
Thanks again
Richard Palmer | Director | Merula Limited
Company Registered in England and Wales No. 3243995
5 Avro Court, Huntingdon, Cambridgeshire, PE29 6XS
Phone 01480 222940 | Support 0845 330 0666
Support Email support(a)merula.net
> --- Original message ---
> Subject: Re: Upgrading FreeRadius / MSSQL
> From: <A.L.M.Buxey(a)lboro.ac.uk>
> To: FreeRadius users mailing list
> <freeradius-users(a)lists.freeradius.org>
> Date: Monday, 29/02/2016 10:22 AM
>
> Hi,
>
>>
>> Taking a look at http://wiki.freeradius.org/modules/Rlm_sql I can
>> see that there are 3 possible drivers mentioned for use with mssql -
>> We are currently using freetds - however the site mentions:
>
> I'd say stick with the FreeTDS method if you are happy with it and
> your config
> is currently using it - the ODBC one adds extra elements/dependencies
> into the mix - and you may have extra work to do (not just the local
> FR configuration).
>
> alan
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html
3
2