- Freeradius-Users - lists.freeradius.org

Applying the same rule to multiple values in an attribute/config value
by Stefan Paetow 17 Feb '19

17 Feb '19

Howdy! So, we're reviving the old RFC7542 chestnut because we've found that there is appetite for it. The basic policy for it is done, but a question was raised about the capability to apply the functionality to multiple realms. The basics are this: if (&request:User-Name =~ /([a-zA-Z0-9\.-]+)!([a-zA-Z0-9\.-]*)\(a)(.+)/) { # Store the three parts of the User-Name, store the original User-Name too update control { RFC7542-User-Name := &User-Name } # Format: not_local_realm!...@local_realm: Rewrite User-Name for suffix if (("%{1}" != "${policy.rfc7542_suffix}") && ("%{3}" == "${policy.rfc7542_suffix}")) { update request { User-Name := "%{2}@%{1}" } } # Format: local_realm!...@not_local_realm: Rewrite User-Name for suffix if (("%{1}" == "${policy.rfc7542_suffix}") && ("%{3}" != "${policy.rfc7542_suffix}")) { update request { User-Name := "%{2}@%{1}" } } # end of if suffix # Restore the User-Name to its original glory. if (&control:RFC7542-User-Name && (&request:User-Name != &control:RFC7542-User-Name)) { update request { User-Name := &control:RFC7542-User-Name } update control { RFC7542-User-Name !* ANY } } The question now is the '$policy.rfc7542_suffix' bit. This is currently just defined as a simple value, i.e. 'blahblah.realm'. If we were to define it as a multiple value (semicolon-separated), would it make sense to use a foreach() loop across it, turn each entry into a variable and just check if the value is contained in the regex? The worry I have here is that there's a lot of processing to do, a lot of looping, and if the powers that be (Alan, Arran, Matthew et al) have a better suggestion, I'd love to hear it. Please remember, this is for 3.0.x, with looking at upstreaming this to you guys to give FR RFC7542 capabilities. I await your suggestions :-) With Regards Stefan Paetow Consultant, Trust and Identity t: +44 (0)1235 822 125 gpg: 0x3FCE5142 xmpp: stefanp(a)jabber.dev.ja.net skype: stefan.paetow.janet jisc.ac.uk Jisc is a registered charity (number 1149740) and a company limited by guarantee which is registered in England under Company No. 5747339, VAT No. GB 197 0632 86. Jisc’s registered office is: One Castlepark, Tower Hill, Bristol, BS2 0JA. T 0203 697 5800.

4 22

changed from 2.2.8 to FreeRADIUS Version 3.0.16 now Access-Reject
by Stefan Rudat 16 Feb '19

16 Feb '19

Hello I struggle analysing the trace file finding the miss-configuration. I change the server ( daloRADIUS FreeRADIUS Version 2.2.8 to FreeRADIUS Version 3.0 ) and get now always Access-Reject. It would be very useful to get a hint how to go forward, I’m to blind to find my fault works perfekt FreeRADIUS Version 2.2.8, for host x86_64-pc-linux-gnu, built on Jul 26 2017 at 15:27:21 Sent Access-Reject FreeRADIUS Version 3.0.16, for host x86_64-pc-linux-gnu, built on Feb 28 2018 at 06:51:17 maybe that is the reason why it fails ?? "Authentication will fail unless a "known good" password is available“ mysql +----+----------+--------------------+----+-----------+ | id | username | attribute | op | value | +----+----------+--------------------+----+-----------+ | 5 | stefan | Cleartext-Password | := | frankfurt | +----+----------+--------------------+----+-----------+ +----+----------------+-----------+-------+-------+------------+--------+-----------+-------------+ | id | nasname | shortname | type | ports | secret | server | community | description | +----+----------------+-----------+-------+-------+------------+--------+-----------+-------------+ | 1 | 192.168.178.27 | local | other | 0 | testing123 | | | | | 2 | 127.0.0.1 | localhost | other | 0 | testing123 | | | | +----+----------------+-----------+-------+-------+------------+--------+-----------+-------------+ radtest stefan frankfurt localhost 18128 testing123 Sent Access-Request Id 205 from 0.0.0.0:38947 to 127.0.0.1:1812 length 76 User-Name = "stefan" User-Password = "frankfurt" NAS-IP-Address = 192.168.178.27 NAS-Port = 18128 Message-Authenticator = 0x00 Cleartext-Password = "frankfurt" Received Access-Reject Id 205 from 127.0.0.1:1812 to 0.0.0.0:0 length 20 (0) -: Expected Access-Accept got Access-Reject I see : Debug: (0) sql: SQL query returned: success WARNING: (1) pap: No "known good" password found for the user. Not setting Auth-Type WARNING: (1) pap: Authentication will fail unless a "known good" password is available ERROR: (1) No Auth-Type found: rejecting the user via Post-Auth-Type = Reject Debug: (0) attr_filter.access_reject: --> stefan Debug: (0) attr_filter.access_reject: Matched entry DEFAULT at line 11 Below the trace and the default ------------------------------ trace ------------------------------------- freeradius -Xxxx Fri Feb 15 22:33:18 2019 : Debug: Server was built with: Fri Feb 15 22:33:18 2019 : Debug: accounting : yes Fri Feb 15 22:33:18 2019 : Debug: authentication : yes Fri Feb 15 22:33:18 2019 : Debug: ascend-binary-attributes : yes Fri Feb 15 22:33:18 2019 : Debug: coa : yes Fri Feb 15 22:33:18 2019 : Debug: control-socket : yes Fri Feb 15 22:33:18 2019 : Debug: detail : yes Fri Feb 15 22:33:18 2019 : Debug: dhcp : yes Fri Feb 15 22:33:18 2019 : Debug: dynamic-clients : yes Fri Feb 15 22:33:18 2019 : Debug: osfc2 : no Fri Feb 15 22:33:18 2019 : Debug: proxy : yes Fri Feb 15 22:33:18 2019 : Debug: regex-pcre : yes Fri Feb 15 22:33:18 2019 : Debug: regex-posix : no Fri Feb 15 22:33:18 2019 : Debug: regex-posix-extended : no Fri Feb 15 22:33:18 2019 : Debug: session-management : yes Fri Feb 15 22:33:18 2019 : Debug: stats : yes Fri Feb 15 22:33:18 2019 : Debug: tcp : yes Fri Feb 15 22:33:18 2019 : Debug: threads : yes Fri Feb 15 22:33:18 2019 : Debug: tls : yes Fri Feb 15 22:33:18 2019 : Debug: unlang : yes Fri Feb 15 22:33:18 2019 : Debug: vmps : yes Fri Feb 15 22:33:18 2019 : Debug: developer : no Fri Feb 15 22:33:18 2019 : Debug: Server core libs: Fri Feb 15 22:33:18 2019 : Debug: freeradius-server : 3.0.16 Fri Feb 15 22:33:18 2019 : Debug: talloc : 2.1.* Fri Feb 15 22:33:18 2019 : Debug: ssl : 1.1.0g release Fri Feb 15 22:33:18 2019 : Debug: pcre : 8.39 2016-06-14 Fri Feb 15 22:33:18 2019 : Debug: Endianness: Fri Feb 15 22:33:18 2019 : Debug: little Fri Feb 15 22:33:18 2019 : Debug: Compilation flags: Fri Feb 15 22:33:18 2019 : Debug: cppflags : -Wdate-time -D_FORTIFY_SOURCE=2 Fri Feb 15 22:33:18 2019 : Debug: cflags : -I. -Isrc -include src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h -include src/freeradius-devel/features.h -include src/freeradius-devel/radpaths.h -fno-strict-aliasing -Wno-date-time -g -O2 -fdebug-prefix-map=/build/freeradius-4V8Upi/freeradius-3.0.16+dfsg=. -fstack-protector-strong -Wformat -Werror=format-security -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -DNDEBUG -DIS_MODULE=1 Fri Feb 15 22:33:18 2019 : Debug: ldflags : -Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now Fri Feb 15 22:33:18 2019 : Debug: libs : -lcrypto -lssl -ltalloc -lpcre -lcap -lnsl -lresolv -ldl -lpthread -lreadline Fri Feb 15 22:33:18 2019 : Debug: Fri Feb 15 22:33:18 2019 : Info: FreeRADIUS Version 3.0.16 Fri Feb 15 22:33:18 2019 : Info: Copyright (C) 1999-2017 The FreeRADIUS server project and contributors Fri Feb 15 22:33:18 2019 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Fri Feb 15 22:33:18 2019 : Info: PARTICULAR PURPOSE Fri Feb 15 22:33:18 2019 : Info: You may redistribute copies of FreeRADIUS under the terms of the Fri Feb 15 22:33:18 2019 : Info: GNU General Public License Fri Feb 15 22:33:18 2019 : Info: For more information about these matters, see the file named COPYRIGHT Fri Feb 15 22:33:18 2019 : Info: Starting - reading configuration files ... Fri Feb 15 22:33:18 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary Fri Feb 15 22:33:18 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcp Fri Feb 15 22:33:18 2019 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqp Fri Feb 15 22:33:18 2019 : Debug: including dictionary file /etc/freeradius/3.0/dictionary Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/radiusd.conf Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/proxy.conf Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/clients.conf Fri Feb 15 22:33:18 2019 : Debug: including files in directory /etc/freeradius/3.0/mods-enabled/ Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/replicate Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/echo Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expr Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/logintime Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sql Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-config/sql/main/sqlite/queries.conf Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/files Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/exec Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/utf8 Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/linelog Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/soh Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expiration Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/pap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/mschap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unpack Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/passwd Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/chap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/eap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/digest Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/preprocess Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/radutmp Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unix Fri Feb 15 22:33:18 2019 : Debug: including files in directory /etc/freeradius/3.0/policy.d/ Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/canonicalization Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/cui Fri Feb 15 22:33:18 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Fri Feb 15 22:33:18 2019 : Debug: OPTIMIZING (no == yes) --> FALSE Fri Feb 15 22:33:18 2019 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Fri Feb 15 22:33:18 2019 : Debug: OPTIMIZING (no == yes) --> FALSE Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/filter Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/operator-name Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/debug Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/dhcp Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/abfab-tr Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/accounting Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/eap Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/policy.d/control Fri Feb 15 22:33:18 2019 : Debug: including files in directory /etc/freeradius/3.0/sites-enabled/ Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/default Fri Feb 15 22:33:18 2019 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/inner-tunnel Fri Feb 15 22:33:18 2019 : Debug: main { Fri Feb 15 22:33:18 2019 : Debug: security { Fri Feb 15 22:33:18 2019 : Debug: user = "freerad" Fri Feb 15 22:33:18 2019 : Debug: group = "freerad" Fri Feb 15 22:33:18 2019 : Debug: allow_core_dumps = no Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: name = "freeradius" Fri Feb 15 22:33:18 2019 : Debug: prefix = "/usr" Fri Feb 15 22:33:18 2019 : Debug: localstatedir = "/var" Fri Feb 15 22:33:18 2019 : Debug: logdir = "/var/log/freeradius" Fri Feb 15 22:33:18 2019 : Debug: run_dir = "/var/run/freeradius" Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[483]: The item 'proxy_requests' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: main { Fri Feb 15 22:33:18 2019 : Debug: name = "freeradius" Fri Feb 15 22:33:18 2019 : Debug: prefix = "/usr" Fri Feb 15 22:33:18 2019 : Debug: localstatedir = "/var" Fri Feb 15 22:33:18 2019 : Debug: sbindir = "/usr/sbin" Fri Feb 15 22:33:18 2019 : Debug: logdir = "/var/log/freeradius" Fri Feb 15 22:33:18 2019 : Debug: run_dir = "/var/run/freeradius" Fri Feb 15 22:33:18 2019 : Debug: libdir = "/usr/lib/freeradius" Fri Feb 15 22:33:18 2019 : Debug: radacctdir = "/var/log/freeradius/radacct" Fri Feb 15 22:33:18 2019 : Debug: hostname_lookups = no Fri Feb 15 22:33:18 2019 : Debug: max_request_time = 30 Fri Feb 15 22:33:18 2019 : Debug: cleanup_delay = 5 Fri Feb 15 22:33:18 2019 : Debug: max_requests = 16384 Fri Feb 15 22:33:18 2019 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Fri Feb 15 22:33:18 2019 : Debug: checkrad = "/usr/sbin/checkrad" Fri Feb 15 22:33:18 2019 : Debug: debug_level = 0 Fri Feb 15 22:33:18 2019 : Debug: proxy_requests = yes Fri Feb 15 22:33:18 2019 : Debug: log { Fri Feb 15 22:33:18 2019 : Debug: stripped_names = no Fri Feb 15 22:33:18 2019 : Debug: auth = no Fri Feb 15 22:33:18 2019 : Debug: auth_badpass = no Fri Feb 15 22:33:18 2019 : Debug: auth_goodpass = no Fri Feb 15 22:33:18 2019 : Debug: colourise = yes Fri Feb 15 22:33:18 2019 : Debug: msg_denied = "You are already logged in - access denied" Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: resources { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: security { Fri Feb 15 22:33:18 2019 : Debug: max_attributes = 200 Fri Feb 15 22:33:18 2019 : Debug: reject_delay = 1.000000 Fri Feb 15 22:33:18 2019 : Debug: status_server = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: radiusd: #### Loading Realms and Home Servers #### Fri Feb 15 22:33:18 2019 : Debug: proxy server { Fri Feb 15 22:33:18 2019 : Debug: retry_delay = 5 Fri Feb 15 22:33:18 2019 : Debug: retry_count = 3 Fri Feb 15 22:33:18 2019 : Debug: default_fallback = no Fri Feb 15 22:33:18 2019 : Debug: dead_time = 120 Fri Feb 15 22:33:18 2019 : Debug: wake_all_if_all_dead = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: home_server localhost { Fri Feb 15 22:33:18 2019 : Debug: ipaddr = 127.0.0.1 Fri Feb 15 22:33:18 2019 : Debug: port = 1812 Fri Feb 15 22:33:18 2019 : Debug: type = "auth" Fri Feb 15 22:33:18 2019 : Debug: secret = "testing123" Fri Feb 15 22:33:18 2019 : Debug: response_window = 20.000000 Fri Feb 15 22:33:18 2019 : Debug: response_timeouts = 1 Fri Feb 15 22:33:18 2019 : Debug: max_outstanding = 65536 Fri Feb 15 22:33:18 2019 : Debug: zombie_period = 40 Fri Feb 15 22:33:18 2019 : Debug: status_check = "status-server" Fri Feb 15 22:33:18 2019 : Debug: ping_interval = 30 Fri Feb 15 22:33:18 2019 : Debug: check_interval = 30 Fri Feb 15 22:33:18 2019 : Debug: check_timeout = 4 Fri Feb 15 22:33:18 2019 : Debug: num_answers_to_alive = 3 Fri Feb 15 22:33:18 2019 : Debug: revive_interval = 120 Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: max_requests = 0 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 0 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: coa { Fri Feb 15 22:33:18 2019 : Debug: irt = 2 Fri Feb 15 22:33:18 2019 : Debug: mrt = 16 Fri Feb 15 22:33:18 2019 : Debug: mrc = 5 Fri Feb 15 22:33:18 2019 : Debug: mrd = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: home_server_pool my_auth_failover { Fri Feb 15 22:33:18 2019 : Debug: type = fail-over Fri Feb 15 22:33:18 2019 : Debug: home_server = localhost Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: realm example.com { Fri Feb 15 22:33:18 2019 : Debug: auth_pool = my_auth_failover Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: realm LOCAL { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: radiusd: #### Loading Clients #### Fri Feb 15 22:33:18 2019 : Debug: client localhost { Fri Feb 15 22:33:18 2019 : Debug: ipaddr = 127.0.0.1 Fri Feb 15 22:33:18 2019 : Debug: require_message_authenticator = no Fri Feb 15 22:33:18 2019 : Debug: secret = "testing123" Fri Feb 15 22:33:18 2019 : Debug: nas_type = "other" Fri Feb 15 22:33:18 2019 : Debug: proto = "*" Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Fri Feb 15 22:33:18 2019 : Debug: client localhost_ipv6 { Fri Feb 15 22:33:18 2019 : Debug: ipv6addr = ::1 Fri Feb 15 22:33:18 2019 : Debug: require_message_authenticator = no Fri Feb 15 22:33:18 2019 : Debug: secret = "testing123" Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Adding client ::1/128 (::1) to prefix tree 128 Fri Feb 15 22:33:18 2019 : Info: Debugger not attached Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = mschap Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = digest Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = eap Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = PAP Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = CHAP Fri Feb 15 22:33:18 2019 : Debug: # Creating Auth-Type = MS-CHAP Fri Feb 15 22:33:18 2019 : Debug: radiusd: #### Instantiating modules #### Fri Feb 15 22:33:18 2019 : Debug: modules { Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_replicate with path: /usr/lib/freeradius/rlm_replicate.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_replicate, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_replicate Fri Feb 15 22:33:18 2019 : Debug: # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_cache with path: /usr/lib/freeradius/rlm_cache.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_cache, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_cache Fri Feb 15 22:33:18 2019 : Debug: # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap Fri Feb 15 22:33:18 2019 : Debug: cache cache_eap { Fri Feb 15 22:33:18 2019 : Debug: driver = "rlm_cache_rbtree" Fri Feb 15 22:33:18 2019 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" Fri Feb 15 22:33:18 2019 : Debug: ttl = 15 Fri Feb 15 22:33:18 2019 : Debug: max_entries = 0 Fri Feb 15 22:33:18 2019 : Debug: epoch = 0 Fri Feb 15 22:33:18 2019 : Debug: add_stats = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_attr_filter with path: /usr/lib/freeradius/rlm_attr_filter.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_attr_filter, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_attr_filter Fri Feb 15 22:33:18 2019 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: attr_filter attr_filter.post-proxy { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy" Fri Feb 15 22:33:18 2019 : Debug: key = "%{Realm}" Fri Feb 15 22:33:18 2019 : Debug: relaxed = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: attr_filter attr_filter.pre-proxy { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy" Fri Feb 15 22:33:18 2019 : Debug: key = "%{Realm}" Fri Feb 15 22:33:18 2019 : Debug: relaxed = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: attr_filter attr_filter.access_reject { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject" Fri Feb 15 22:33:18 2019 : Debug: key = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: relaxed = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: attr_filter attr_filter.access_challenge { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge" Fri Feb 15 22:33:18 2019 : Debug: key = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: relaxed = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: attr_filter attr_filter.accounting_response { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response" Fri Feb 15 22:33:18 2019 : Debug: key = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: relaxed = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_exec, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_exec Fri Feb 15 22:33:18 2019 : Debug: # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo Fri Feb 15 22:33:18 2019 : Debug: exec echo { Fri Feb 15 22:33:18 2019 : Debug: wait = yes Fri Feb 15 22:33:18 2019 : Debug: program = "/bin/echo %{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: input_pairs = "request" Fri Feb 15 22:33:18 2019 : Debug: output_pairs = "reply" Fri Feb 15 22:33:18 2019 : Debug: shell_escape = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_expr, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_expr Fri Feb 15 22:33:18 2019 : Debug: # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr Fri Feb 15 22:33:18 2019 : Debug: expr { Fri Feb 15 22:33:18 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_logintime with path: /usr/lib/freeradius/rlm_logintime.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_logintime, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_logintime Fri Feb 15 22:33:18 2019 : Debug: # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime Fri Feb 15 22:33:18 2019 : Debug: logintime { Fri Feb 15 22:33:18 2019 : Debug: minimum_timeout = 60 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_always with path: /usr/lib/freeradius/rlm_always.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_always, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_always Fri Feb 15 22:33:18 2019 : Debug: # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always reject { Fri Feb 15 22:33:18 2019 : Debug: rcode = "reject" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always fail { Fri Feb 15 22:33:18 2019 : Debug: rcode = "fail" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always ok { Fri Feb 15 22:33:18 2019 : Debug: rcode = "ok" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always handled { Fri Feb 15 22:33:18 2019 : Debug: rcode = "handled" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always invalid { Fri Feb 15 22:33:18 2019 : Debug: rcode = "invalid" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always userlock { Fri Feb 15 22:33:18 2019 : Debug: rcode = "userlock" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always notfound { Fri Feb 15 22:33:18 2019 : Debug: rcode = "notfound" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always noop { Fri Feb 15 22:33:18 2019 : Debug: rcode = "noop" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: always updated { Fri Feb 15 22:33:18 2019 : Debug: rcode = "updated" Fri Feb 15 22:33:18 2019 : Debug: simulcount = 0 Fri Feb 15 22:33:18 2019 : Debug: mpp = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_sql with path: /usr/lib/freeradius/rlm_sql.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_sql, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_sql Fri Feb 15 22:33:18 2019 : Debug: # Loading module "sql" from file /etc/freeradius/3.0/mods-enabled/sql Fri Feb 15 22:33:18 2019 : Debug: sql { Fri Feb 15 22:33:18 2019 : Debug: driver = "rlm_sql_null" Fri Feb 15 22:33:18 2019 : Debug: server = "" Fri Feb 15 22:33:18 2019 : Debug: port = 0 Fri Feb 15 22:33:18 2019 : Debug: login = "" Fri Feb 15 22:33:18 2019 : Debug: password = "7z36tat" Fri Feb 15 22:33:18 2019 : Debug: radius_db = "radius" Fri Feb 15 22:33:18 2019 : Debug: read_groups = yes Fri Feb 15 22:33:18 2019 : Debug: read_profiles = yes Fri Feb 15 22:33:18 2019 : Debug: read_clients = yes Fri Feb 15 22:33:18 2019 : Debug: delete_stale_sessions = yes Fri Feb 15 22:33:18 2019 : Debug: sql_user_name = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: default_user_profile = "" Fri Feb 15 22:33:18 2019 : Debug: client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Fri Feb 15 22:33:18 2019 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" Fri Feb 15 22:33:18 2019 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" Fri Feb 15 22:33:18 2019 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id" Fri Feb 15 22:33:18 2019 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id" Fri Feb 15 22:33:18 2019 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" Fri Feb 15 22:33:18 2019 : Debug: simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Fri Feb 15 22:33:18 2019 : Debug: accounting { Fri Feb 15 22:33:18 2019 : Debug: reference = "%{tolower:type.%{Acct-Status-Type}.query}" Fri Feb 15 22:33:18 2019 : Debug: type { Fri Feb 15 22:33:18 2019 : Debug: accounting-on { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: accounting-off { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: start { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: interim-update { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: stop { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: post-auth { Fri Feb 15 22:33:18 2019 : Debug: reference = ".query" Fri Feb 15 22:33:18 2019 : Debug: query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_sql_null with path: /usr/lib/freeradius/rlm_sql_null.so Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Driver rlm_sql_null (module rlm_sql_null) loaded and linked Fri Feb 15 22:33:18 2019 : Debug: Creating attribute SQL-Group Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_detail, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_detail Fri Feb 15 22:33:18 2019 : Debug: # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: detail auth_log { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Fri Feb 15 22:33:18 2019 : Debug: header = "%t" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: locking = no Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: log_packet_header = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: detail reply_log { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Fri Feb 15 22:33:18 2019 : Debug: header = "%t" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: locking = no Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: log_packet_header = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: detail pre_proxy_log { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Fri Feb 15 22:33:18 2019 : Debug: header = "%t" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: locking = no Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: log_packet_header = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: detail post_proxy_log { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Fri Feb 15 22:33:18 2019 : Debug: header = "%t" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: locking = no Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: log_packet_header = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_files with path: /usr/lib/freeradius/rlm_files.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_files, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_files Fri Feb 15 22:33:18 2019 : Debug: # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files Fri Feb 15 22:33:18 2019 : Debug: files { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/freeradius/3.0/mods-config/files/authorize" Fri Feb 15 22:33:18 2019 : Debug: acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting" Fri Feb 15 22:33:18 2019 : Debug: preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec Fri Feb 15 22:33:18 2019 : Debug: exec { Fri Feb 15 22:33:18 2019 : Debug: wait = no Fri Feb 15 22:33:18 2019 : Debug: input_pairs = "request" Fri Feb 15 22:33:18 2019 : Debug: shell_escape = yes Fri Feb 15 22:33:18 2019 : Debug: timeout = 10 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_utf8 with path: /usr/lib/freeradius/rlm_utf8.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_utf8, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_utf8 Fri Feb 15 22:33:18 2019 : Debug: # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8 Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_radutmp with path: /usr/lib/freeradius/rlm_radutmp.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_radutmp, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_radutmp Fri Feb 15 22:33:18 2019 : Debug: # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp Fri Feb 15 22:33:18 2019 : Debug: radutmp sradutmp { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/sradutmp" Fri Feb 15 22:33:18 2019 : Debug: username = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: case_sensitive = yes Fri Feb 15 22:33:18 2019 : Debug: check_with_nas = yes Fri Feb 15 22:33:18 2019 : Debug: permissions = 420 Fri Feb 15 22:33:18 2019 : Debug: caller_id = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_linelog with path: /usr/lib/freeradius/rlm_linelog.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_linelog, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_linelog Fri Feb 15 22:33:18 2019 : Debug: # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog Fri Feb 15 22:33:18 2019 : Debug: linelog { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/linelog" Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: syslog_severity = "info" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: format = "This is a log message for %{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog Fri Feb 15 22:33:18 2019 : Debug: linelog log_accounting { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/linelog-accounting" Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: syslog_severity = "info" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: format = "" Fri Feb 15 22:33:18 2019 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_soh with path: /usr/lib/freeradius/rlm_soh.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_soh, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_soh Fri Feb 15 22:33:18 2019 : Debug: # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh Fri Feb 15 22:33:18 2019 : Debug: soh { Fri Feb 15 22:33:18 2019 : Debug: dhcp = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_realm with path: /usr/lib/freeradius/rlm_realm.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_realm, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_realm Fri Feb 15 22:33:18 2019 : Debug: # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: realm IPASS { Fri Feb 15 22:33:18 2019 : Debug: format = "prefix" Fri Feb 15 22:33:18 2019 : Debug: delimiter = "/" Fri Feb 15 22:33:18 2019 : Debug: ignore_default = no Fri Feb 15 22:33:18 2019 : Debug: ignore_null = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: realm suffix { Fri Feb 15 22:33:18 2019 : Debug: format = "suffix" Fri Feb 15 22:33:18 2019 : Debug: delimiter = "@" Fri Feb 15 22:33:18 2019 : Debug: ignore_default = no Fri Feb 15 22:33:18 2019 : Debug: ignore_null = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: realm realmpercent { Fri Feb 15 22:33:18 2019 : Debug: format = "suffix" Fri Feb 15 22:33:18 2019 : Debug: delimiter = "%" Fri Feb 15 22:33:18 2019 : Debug: ignore_default = no Fri Feb 15 22:33:18 2019 : Debug: ignore_null = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: realm ntdomain { Fri Feb 15 22:33:18 2019 : Debug: format = "prefix" Fri Feb 15 22:33:18 2019 : Debug: delimiter = "\\" Fri Feb 15 22:33:18 2019 : Debug: ignore_default = no Fri Feb 15 22:33:18 2019 : Debug: ignore_null = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_expiration with path: /usr/lib/freeradius/rlm_expiration.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_expiration, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_expiration Fri Feb 15 22:33:18 2019 : Debug: # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration Fri Feb 15 22:33:18 2019 : Debug: # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail Fri Feb 15 22:33:18 2019 : Debug: detail { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Fri Feb 15 22:33:18 2019 : Debug: header = "%t" Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: locking = no Fri Feb 15 22:33:18 2019 : Debug: escape_filenames = no Fri Feb 15 22:33:18 2019 : Debug: log_packet_header = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_pap, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_pap Fri Feb 15 22:33:18 2019 : Debug: # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/pap Fri Feb 15 22:33:18 2019 : Debug: pap { Fri Feb 15 22:33:18 2019 : Debug: normalise = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_mschap with path: /usr/lib/freeradius/rlm_mschap.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_mschap, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_mschap Fri Feb 15 22:33:18 2019 : Debug: # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap Fri Feb 15 22:33:18 2019 : Debug: mschap { Fri Feb 15 22:33:18 2019 : Debug: use_mppe = yes Fri Feb 15 22:33:18 2019 : Debug: require_encryption = no Fri Feb 15 22:33:18 2019 : Debug: require_strong = no Fri Feb 15 22:33:18 2019 : Debug: with_ntdomain_hack = yes Fri Feb 15 22:33:18 2019 : Debug: passchange { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: allow_retry = yes Fri Feb 15 22:33:18 2019 : Debug: winbind_retry_with_normalised_username = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth Fri Feb 15 22:33:18 2019 : Debug: exec ntlm_auth { Fri Feb 15 22:33:18 2019 : Debug: wait = yes Fri Feb 15 22:33:18 2019 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Fri Feb 15 22:33:18 2019 : Debug: shell_escape = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_unpack with path: /usr/lib/freeradius/rlm_unpack.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_unpack, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_unpack Fri Feb 15 22:33:18 2019 : Debug: # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_passwd with path: /usr/lib/freeradius/rlm_passwd.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_passwd, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_passwd Fri Feb 15 22:33:18 2019 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd Fri Feb 15 22:33:18 2019 : Debug: passwd etc_passwd { Fri Feb 15 22:33:18 2019 : Debug: filename = "/etc/passwd" Fri Feb 15 22:33:18 2019 : Debug: format = "*User-Name:Crypt-Password:" Fri Feb 15 22:33:18 2019 : Debug: delimiter = ":" Fri Feb 15 22:33:18 2019 : Debug: ignore_nislike = no Fri Feb 15 22:33:18 2019 : Debug: ignore_empty = yes Fri Feb 15 22:33:18 2019 : Debug: allow_multiple_keys = no Fri Feb 15 22:33:18 2019 : Debug: hash_size = 100 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_chap, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_chap Fri Feb 15 22:33:18 2019 : Debug: # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap with path: /usr/lib/freeradius/rlm_eap.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_eap, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_eap Fri Feb 15 22:33:18 2019 : Debug: # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eap Fri Feb 15 22:33:18 2019 : Debug: eap { Fri Feb 15 22:33:18 2019 : Debug: default_eap_type = "md5" Fri Feb 15 22:33:18 2019 : Debug: timer_expire = 60 Fri Feb 15 22:33:18 2019 : Debug: ignore_unknown_eap_types = no Fri Feb 15 22:33:18 2019 : Debug: cisco_accounting_username_bug = no Fri Feb 15 22:33:18 2019 : Debug: max_sessions = 16384 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_digest with path: /usr/lib/freeradius/rlm_digest.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_digest, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_digest Fri Feb 15 22:33:18 2019 : Debug: # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_preprocess, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_preprocess Fri Feb 15 22:33:18 2019 : Debug: # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess Fri Feb 15 22:33:18 2019 : Debug: preprocess { Fri Feb 15 22:33:18 2019 : Debug: huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups" Fri Feb 15 22:33:18 2019 : Debug: hints = "/etc/freeradius/3.0/mods-config/preprocess/hints" Fri Feb 15 22:33:18 2019 : Debug: with_ascend_hack = no Fri Feb 15 22:33:18 2019 : Debug: ascend_channels_per_line = 23 Fri Feb 15 22:33:18 2019 : Debug: with_ntdomain_hack = no Fri Feb 15 22:33:18 2019 : Debug: with_specialix_jetstream_hack = no Fri Feb 15 22:33:18 2019 : Debug: with_cisco_vsa_hack = no Fri Feb 15 22:33:18 2019 : Debug: with_alvarion_vsa_hack = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_dynamic_clients with path: /usr/lib/freeradius/rlm_dynamic_clients.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_dynamic_clients, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_dynamic_clients Fri Feb 15 22:33:18 2019 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients Fri Feb 15 22:33:18 2019 : Debug: # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp Fri Feb 15 22:33:18 2019 : Debug: radutmp { Fri Feb 15 22:33:18 2019 : Debug: filename = "/var/log/freeradius/radutmp" Fri Feb 15 22:33:18 2019 : Debug: username = "%{User-Name}" Fri Feb 15 22:33:18 2019 : Debug: case_sensitive = yes Fri Feb 15 22:33:18 2019 : Debug: check_with_nas = yes Fri Feb 15 22:33:18 2019 : Debug: permissions = 384 Fri Feb 15 22:33:18 2019 : Debug: caller_id = yes Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_unix with path: /usr/lib/freeradius/rlm_unix.so Fri Feb 15 22:33:18 2019 : Debug: Loaded rlm_unix, checking if it's valid Fri Feb 15 22:33:18 2019 : Debug: # Loaded module rlm_unix Fri Feb 15 22:33:18 2019 : Debug: # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix Fri Feb 15 22:33:18 2019 : Debug: unix { Fri Feb 15 22:33:18 2019 : Debug: radwtmp = "/var/log/freeradius/radwtmp" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Creating attribute Unix-Group Fri Feb 15 22:33:18 2019 : Debug: instantiate { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_cache_rbtree with path: /usr/lib/freeradius/rlm_cache_rbtree.so Fri Feb 15 22:33:18 2019 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject Fri Feb 15 22:33:18 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Fri Feb 15 22:33:18 2019 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec"found in filter list for realm "DEFAULT". Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "sql" from file /etc/freeradius/3.0/mods-enabled/sql Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Attempting to connect to database "radius" Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Using local pool section Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): No pool reference found for config item "sql.pool" Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Initialising connection pool Fri Feb 15 22:33:18 2019 : Debug: pool { Fri Feb 15 22:33:18 2019 : Debug: start = 5 Fri Feb 15 22:33:18 2019 : Debug: min = 3 Fri Feb 15 22:33:18 2019 : Debug: max = 32 Fri Feb 15 22:33:18 2019 : Debug: spare = 10 Fri Feb 15 22:33:18 2019 : Debug: uses = 0 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: cleanup_interval = 30 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 60 Fri Feb 15 22:33:18 2019 : Debug: retry_delay = 30 Fri Feb 15 22:33:18 2019 : Debug: spread = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (0), 1 of 32 pending slots used Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (1), 1 of 31 pending slots used Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (2), 1 of 30 pending slots used Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (3), 1 of 29 pending slots used Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (4), 1 of 28 pending slots used Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Adding pool reference 0x55f6c43879a0 to config item "sql.pool" Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Processing generate_sql_clients Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Reserved connection (0) Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Executing select query: SELECT id, nasname, shortname, type, secret, server FROM nas Fri Feb 15 22:33:18 2019 : Debug: rlm_sql (sql): Released connection (0) Fri Feb 15 22:33:18 2019 : Info: Need 5 more connections to reach 10 spares Fri Feb 15 22:33:18 2019 : Info: rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/pap Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap Fri Feb 15 22:33:18 2019 : Debug: rlm_mschap (mschap): using internal authentication Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd Fri Feb 15 22:33:18 2019 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eap Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_md5 with path: /usr/lib/freeradius/rlm_eap_md5.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_md5 Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_leap with path: /usr/lib/freeradius/rlm_eap_leap.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_leap Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_gtc with path: /usr/lib/freeradius/rlm_eap_gtc.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_gtc Fri Feb 15 22:33:18 2019 : Debug: gtc { Fri Feb 15 22:33:18 2019 : Debug: challenge = "Password: " Fri Feb 15 22:33:18 2019 : Debug: auth_type = "PAP" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_tls with path: /usr/lib/freeradius/rlm_eap_tls.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_tls Fri Feb 15 22:33:18 2019 : Debug: tls { Fri Feb 15 22:33:18 2019 : Debug: tls = "tls-common" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: tls-config tls-common { Fri Feb 15 22:33:18 2019 : Debug: verify_depth = 0 Fri Feb 15 22:33:18 2019 : Debug: ca_path = "/etc/freeradius/3.0/certs" Fri Feb 15 22:33:18 2019 : Debug: pem_file_type = yes Fri Feb 15 22:33:18 2019 : Debug: private_key_file = "/etc/ssl/private/ssl-cert-snakeoil.key" Fri Feb 15 22:33:18 2019 : Debug: certificate_file = "/etc/ssl/certs/ssl-cert-snakeoil.pem" Fri Feb 15 22:33:18 2019 : Debug: ca_file = "/etc/ssl/certs/ca-certificates.crt" Fri Feb 15 22:33:18 2019 : Debug: private_key_password = "whatever" Fri Feb 15 22:33:18 2019 : Debug: dh_file = "/etc/freeradius/3.0/certs/dh" Fri Feb 15 22:33:18 2019 : Debug: fragment_size = 1024 Fri Feb 15 22:33:18 2019 : Debug: include_length = yes Fri Feb 15 22:33:18 2019 : Debug: auto_chain = yes Fri Feb 15 22:33:18 2019 : Debug: check_crl = no Fri Feb 15 22:33:18 2019 : Debug: check_all_crl = no Fri Feb 15 22:33:18 2019 : Debug: cipher_list = "DEFAULT" Fri Feb 15 22:33:18 2019 : Debug: cipher_server_preference = no Fri Feb 15 22:33:18 2019 : Debug: ecdh_curve = "prime256v1" Fri Feb 15 22:33:18 2019 : Debug: tls_max_version = "" Fri Feb 15 22:33:18 2019 : Debug: tls_min_version = "1.0" Fri Feb 15 22:33:18 2019 : Debug: cache { Fri Feb 15 22:33:18 2019 : Debug: enable = no Fri Feb 15 22:33:18 2019 : Debug: lifetime = 24 Fri Feb 15 22:33:18 2019 : Debug: max_entries = 255 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: verify { Fri Feb 15 22:33:18 2019 : Debug: skip_if_ocsp_ok = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: ocsp { Fri Feb 15 22:33:18 2019 : Debug: enable = no Fri Feb 15 22:33:18 2019 : Debug: override_cert_url = yes Fri Feb 15 22:33:18 2019 : Debug: url = "http://127.0.0.1/ocsp/" Fri Feb 15 22:33:18 2019 : Debug: use_nonce = yes Fri Feb 15 22:33:18 2019 : Debug: timeout = 0 Fri Feb 15 22:33:18 2019 : Debug: softfail = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_ttls with path: /usr/lib/freeradius/rlm_eap_ttls.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_ttls Fri Feb 15 22:33:18 2019 : Debug: ttls { Fri Feb 15 22:33:18 2019 : Debug: tls = "tls-common" Fri Feb 15 22:33:18 2019 : Debug: default_eap_type = "md5" Fri Feb 15 22:33:18 2019 : Debug: copy_request_to_tunnel = no Fri Feb 15 22:33:18 2019 : Debug: use_tunneled_reply = no Fri Feb 15 22:33:18 2019 : Debug: virtual_server = "inner-tunnel" Fri Feb 15 22:33:18 2019 : Debug: include_length = yes Fri Feb 15 22:33:18 2019 : Debug: require_client_cert = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: tls: Using cached TLS configuration from previous invocation Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_peap with path: /usr/lib/freeradius/rlm_eap_peap.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_peap Fri Feb 15 22:33:18 2019 : Debug: peap { Fri Feb 15 22:33:18 2019 : Debug: tls = "tls-common" Fri Feb 15 22:33:18 2019 : Debug: default_eap_type = "mschapv2" Fri Feb 15 22:33:18 2019 : Debug: copy_request_to_tunnel = no Fri Feb 15 22:33:18 2019 : Debug: use_tunneled_reply = no Fri Feb 15 22:33:18 2019 : Debug: proxy_tunneled_request_as_eap = yes Fri Feb 15 22:33:18 2019 : Debug: virtual_server = "inner-tunnel" Fri Feb 15 22:33:18 2019 : Debug: soh = no Fri Feb 15 22:33:18 2019 : Debug: require_client_cert = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: tls: Using cached TLS configuration from previous invocation Fri Feb 15 22:33:18 2019 : Debug: Loading rlm_eap_mschapv2 with path: /usr/lib/freeradius/rlm_eap_mschapv2.so Fri Feb 15 22:33:18 2019 : Debug: # Linked to sub-module rlm_eap_mschapv2 Fri Feb 15 22:33:18 2019 : Debug: mschapv2 { Fri Feb 15 22:33:18 2019 : Debug: with_ntdomain_hack = no Fri Feb 15 22:33:18 2019 : Debug: send_error = no Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups Fri Feb 15 22:33:18 2019 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints Fri Feb 15 22:33:18 2019 : Debug: } # modules Fri Feb 15 22:33:18 2019 : Debug: radiusd: #### Loading Virtual Servers #### Fri Feb 15 22:33:18 2019 : Debug: server { # from file /etc/freeradius/3.0/radiusd.conf Fri Feb 15 22:33:18 2019 : Debug: } # server Fri Feb 15 22:33:18 2019 : Debug: server default { # from file /etc/freeradius/3.0/sites-enabled/default Fri Feb 15 22:33:18 2019 : Debug: authenticate { Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: pap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: chap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: digest Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: } # authenticate Fri Feb 15 22:33:18 2019 : Debug: authorize { Fri Feb 15 22:33:18 2019 : Debug: policy filter_username { Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name) { Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ / /) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /@[^@]*@/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /\.\./) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /\.$/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /(a)\./) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: preprocess Fri Feb 15 22:33:18 2019 : Debug: chap Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: digest Fri Feb 15 22:33:18 2019 : Debug: suffix Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: files Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Warning: Ignoring "ldap" (see raddb/mods-available/README.rst) Fri Feb 15 22:33:18 2019 : Debug: expiration Fri Feb 15 22:33:18 2019 : Debug: logintime Fri Feb 15 22:33:18 2019 : Debug: pap Fri Feb 15 22:33:18 2019 : Debug: } # authorize Fri Feb 15 22:33:18 2019 : Debug: preacct { Fri Feb 15 22:33:18 2019 : Debug: preprocess Fri Feb 15 22:33:18 2019 : Debug: policy acct_unique { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Tmp-String-9 := "ai:" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}" Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: else { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : 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 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: suffix Fri Feb 15 22:33:18 2019 : Debug: files Fri Feb 15 22:33:18 2019 : Debug: } # preacct Fri Feb 15 22:33:18 2019 : Debug: accounting { Fri Feb 15 22:33:18 2019 : Debug: detail Fri Feb 15 22:33:18 2019 : Debug: unix Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Debug: exec Fri Feb 15 22:33:18 2019 : Debug: attr_filter.accounting_response Fri Feb 15 22:33:18 2019 : Debug: } # accounting Fri Feb 15 22:33:18 2019 : Debug: post-proxy { Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: } # post-proxy Fri Feb 15 22:33:18 2019 : Debug: post-auth { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &reply:[*] += &session-state:[*] Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Debug: exec Fri Feb 15 22:33:18 2019 : Debug: policy remove_reply_message_if_eap { Fri Feb 15 22:33:18 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &reply:Reply-Message !* ANY Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: else { Fri Feb 15 22:33:18 2019 : Debug: noop Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Debug: attr_filter.access_reject Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: policy remove_reply_message_if_eap { Fri Feb 15 22:33:18 2019 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &reply:Reply-Message !* ANY Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: else { Fri Feb 15 22:33:18 2019 : Debug: noop Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } # post-auth Fri Feb 15 22:33:18 2019 : Debug: } # server default Fri Feb 15 22:33:18 2019 : Debug: server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnel Fri Feb 15 22:33:18 2019 : Debug: authenticate { Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: pap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: chap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: } # authenticate Fri Feb 15 22:33:18 2019 : Debug: authorize { Fri Feb 15 22:33:18 2019 : Debug: policy filter_username { Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name) { Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ / /) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /@[^@]*@/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /\.\./) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /(a)(.+)\.(.+)$/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /\.$/) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: if (&User-Name =~ /(a)\./) { Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: reject Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: chap Fri Feb 15 22:33:18 2019 : Debug: mschap Fri Feb 15 22:33:18 2019 : Debug: suffix Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &control:Proxy-To-Realm := LOCAL Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: files Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Debug: expiration Fri Feb 15 22:33:18 2019 : Debug: logintime Fri Feb 15 22:33:18 2019 : Debug: pap Fri Feb 15 22:33:18 2019 : Debug: } # authorize Fri Feb 15 22:33:18 2019 : Debug: session { Fri Feb 15 22:33:18 2019 : Debug: radutmp Fri Feb 15 22:33:18 2019 : Debug: } # session Fri Feb 15 22:33:18 2019 : Debug: post-proxy { Fri Feb 15 22:33:18 2019 : Debug: eap Fri Feb 15 22:33:18 2019 : Debug: } # post-proxy Fri Feb 15 22:33:18 2019 : Debug: post-auth { Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Info: # Skipping contents of 'if' as it is always 'false' -- /etc/freeradius/3.0/sites-enabled/inner-tunnel:331 Fri Feb 15 22:33:18 2019 : Debug: if (false) { Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: group { Fri Feb 15 22:33:18 2019 : Debug: sql Fri Feb 15 22:33:18 2019 : Debug: attr_filter.access_reject Fri Feb 15 22:33:18 2019 : Debug: update { Fri Feb 15 22:33:18 2019 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } # post-auth Fri Feb 15 22:33:18 2019 : Debug: } # server inner-tunnel Fri Feb 15 22:33:18 2019 : Debug: Created signal pipe. Read end FD 5, write end FD 6 Fri Feb 15 22:33:18 2019 : Debug: radiusd: #### Opening IP addresses and Ports #### Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Fri Feb 15 22:33:18 2019 : Debug: Loading library using linker search path(s) Fri Feb 15 22:33:18 2019 : Debug: Defaults : /lib:/usr/lib Fri Feb 15 22:33:18 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Fri Feb 15 22:33:18 2019 : Debug: listen { Fri Feb 15 22:33:18 2019 : Debug: type = "auth" Fri Feb 15 22:33:18 2019 : Debug: ipaddr = * Fri Feb 15 22:33:18 2019 : Debug: port = 0 Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so Fri Feb 15 22:33:18 2019 : Debug: Loading proto_acct failed: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Fri Feb 15 22:33:18 2019 : Debug: Loading library using linker search path(s) Fri Feb 15 22:33:18 2019 : Debug: Defaults : /lib:/usr/lib Fri Feb 15 22:33:18 2019 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Fri Feb 15 22:33:18 2019 : Debug: listen { Fri Feb 15 22:33:18 2019 : Debug: type = "acct" Fri Feb 15 22:33:18 2019 : Debug: ipaddr = * Fri Feb 15 22:33:18 2019 : Debug: port = 0 Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Fri Feb 15 22:33:18 2019 : Debug: Loading library using linker search path(s) Fri Feb 15 22:33:18 2019 : Debug: Defaults : /lib:/usr/lib Fri Feb 15 22:33:18 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Fri Feb 15 22:33:18 2019 : Debug: listen { Fri Feb 15 22:33:18 2019 : Debug: type = "auth" Fri Feb 15 22:33:18 2019 : Debug: ipv6addr = :: Fri Feb 15 22:33:18 2019 : Debug: port = 0 Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so Fri Feb 15 22:33:18 2019 : Debug: Loading proto_acct failed: /usr/lib/freeradius/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Fri Feb 15 22:33:18 2019 : Debug: Loading library using linker search path(s) Fri Feb 15 22:33:18 2019 : Debug: Defaults : /lib:/usr/lib Fri Feb 15 22:33:18 2019 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Fri Feb 15 22:33:18 2019 : Debug: listen { Fri Feb 15 22:33:18 2019 : Debug: type = "acct" Fri Feb 15 22:33:18 2019 : Debug: ipv6addr = :: Fri Feb 15 22:33:18 2019 : Debug: port = 0 Fri Feb 15 22:33:18 2019 : Debug: limit { Fri Feb 15 22:33:18 2019 : Debug: max_connections = 16 Fri Feb 15 22:33:18 2019 : Debug: lifetime = 0 Fri Feb 15 22:33:18 2019 : Debug: idle_timeout = 30 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Fri Feb 15 22:33:18 2019 : Debug: Loading proto_auth failed: /usr/lib/freeradius/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Fri Feb 15 22:33:18 2019 : Debug: Loading library using linker search path(s) Fri Feb 15 22:33:18 2019 : Debug: Defaults : /lib:/usr/lib Fri Feb 15 22:33:18 2019 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Fri Feb 15 22:33:18 2019 : Debug: listen { Fri Feb 15 22:33:18 2019 : Debug: type = "auth" Fri Feb 15 22:33:18 2019 : Debug: ipaddr = 127.0.0.1 Fri Feb 15 22:33:18 2019 : Debug: port = 18120 Fri Feb 15 22:33:18 2019 : Debug: } Fri Feb 15 22:33:18 2019 : Debug: Listening on auth address * port 1812 bound to server default Fri Feb 15 22:33:18 2019 : Debug: Listening on acct address * port 1813 bound to server default Fri Feb 15 22:33:18 2019 : Debug: Listening on auth address :: port 1812 bound to server default Fri Feb 15 22:33:18 2019 : Debug: Listening on acct address :: port 1813 bound to server default Fri Feb 15 22:33:18 2019 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Fri Feb 15 22:33:18 2019 : Debug: Opened new proxy socket 'proxy address * port 39213' Fri Feb 15 22:33:18 2019 : Debug: Listening on proxy address * port 39213 Fri Feb 15 22:33:18 2019 : Debug: Opened new proxy socket 'proxy address :: port 59111' Fri Feb 15 22:33:18 2019 : Debug: Listening on proxy address :: port 59111 Fri Feb 15 22:33:18 2019 : Info: Ready to process requests Fri Feb 15 22:33:29 2019 : Debug: (0) Received Access-Request Id 109 from 127.0.0.1:47161 to 127.0.0.1:1812 length 76 Fri Feb 15 22:33:29 2019 : Debug: (0) User-Name = "stefan" Fri Feb 15 22:33:29 2019 : Debug: (0) User-Password = "frankfurt" Fri Feb 15 22:33:29 2019 : Debug: (0) NAS-IP-Address = 192.168.178.27 Fri Feb 15 22:33:29 2019 : Debug: (0) NAS-Port = 18128 Fri Feb 15 22:33:29 2019 : Debug: (0) Message-Authenticator = 0x71950e3750476151d2f158fb0f53c12f Fri Feb 15 22:33:29 2019 : Debug: (0) session-state: No State attribute Fri Feb 15 22:33:29 2019 : Debug: (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default Fri Feb 15 22:33:29 2019 : Debug: (0) authorize { Fri Feb 15 22:33:29 2019 : Debug: (0) policy filter_username { Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name) { Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name) -> TRUE Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name) { Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ / /) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ / /) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /\.\./ ) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /\.$/) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /\.$/) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /(a)\./) { Fri Feb 15 22:33:29 2019 : Debug: No matches Fri Feb 15 22:33:29 2019 : Debug: (0) if (&User-Name =~ /(a)\./) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) } # if (&User-Name) = notfound Fri Feb 15 22:33:29 2019 : Debug: (0) } # policy filter_username = notfound Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) Fri Feb 15 22:33:29 2019 : Debug: (0) [preprocess] = ok Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) Fri Feb 15 22:33:29 2019 : Debug: (0) [chap] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) Fri Feb 15 22:33:29 2019 : Debug: (0) [mschap] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) Fri Feb 15 22:33:29 2019 : Debug: (0) [digest] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) Fri Feb 15 22:33:29 2019 : Debug: (0) suffix: Checking for suffix after "@" Fri Feb 15 22:33:29 2019 : Debug: (0) suffix: No '@' in User-Name = "stefan", looking up realm NULL Fri Feb 15 22:33:29 2019 : Debug: (0) suffix: No such realm "NULL" Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) Fri Feb 15 22:33:29 2019 : Debug: (0) [suffix] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) Fri Feb 15 22:33:29 2019 : Debug: (0) eap: No EAP-Message, not doing EAP Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) Fri Feb 15 22:33:29 2019 : Debug: (0) [eap] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling files (rlm_files) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from files (rlm_files) Fri Feb 15 22:33:29 2019 : Debug: (0) [files] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling sql (rlm_sql) Fri Feb 15 22:33:29 2019 : Debug: %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: attribute --> User-Name Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> stefan Fri Feb 15 22:33:29 2019 : Debug: (0) sql: SQL-User-Name set to 'stefan' Fri Feb 15 22:33:29 2019 : Debug: rlm_sql (sql): Reserved connection (1) Fri Feb 15 22:33:29 2019 : Debug: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: literal --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = ' Fri Feb 15 22:33:29 2019 : Debug: attribute --> SQL-User-Name Fri Feb 15 22:33:29 2019 : Debug: literal --> ' ORDER BY id Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'stefan' ORDER BY id Fri Feb 15 22:33:29 2019 : Debug: (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'stefan' ORDER BY id Fri Feb 15 22:33:29 2019 : Debug: (0) sql: ... falling-through to group processing Fri Feb 15 22:33:29 2019 : Debug: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: literal --> SELECT groupname FROM radusergroup WHERE username = ' Fri Feb 15 22:33:29 2019 : Debug: attribute --> SQL-User-Name Fri Feb 15 22:33:29 2019 : Debug: literal --> ' ORDER BY priority Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'stefan' ORDER BY priority Fri Feb 15 22:33:29 2019 : Debug: (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'stefan' ORDER BY priority Fri Feb 15 22:33:29 2019 : Debug: (0) sql: User not found in any groups Fri Feb 15 22:33:29 2019 : Debug: (0) sql: ... falling-through to profile processing Fri Feb 15 22:33:29 2019 : Debug: rlm_sql (sql): Released connection (1) Fri Feb 15 22:33:29 2019 : Info: Need 4 more connections to reach 10 spares Fri Feb 15 22:33:29 2019 : Info: rlm_sql (sql): Opening additional connection (6), 1 of 26 pending slots used Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from sql (rlm_sql) Fri Feb 15 22:33:29 2019 : Debug: (0) [sql] = notfound Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling expiration (rlm_expiration) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from expiration (rlm_expiration) Fri Feb 15 22:33:29 2019 : Debug: (0) [expiration] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling logintime (rlm_logintime) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from logintime (rlm_logintime) Fri Feb 15 22:33:29 2019 : Debug: (0) [logintime] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: calling pap (rlm_pap) Fri Feb 15 22:33:29 2019 : WARNING: (0) pap: No "known good" password found for the user. Not setting Auth-Type Fri Feb 15 22:33:29 2019 : WARNING: (0) pap: Authentication will fail unless a "known good" password is available Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[authorize]: returned from pap (rlm_pap) Fri Feb 15 22:33:29 2019 : Debug: (0) [pap] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) } # authorize = ok Fri Feb 15 22:33:29 2019 : ERROR: (0) No Auth-Type found: rejecting the user via Post-Auth-Type = Reject Fri Feb 15 22:33:29 2019 : Debug: (0) Failed to authenticate the user Fri Feb 15 22:33:29 2019 : Debug: (0) Using Post-Auth-Type Reject Fri Feb 15 22:33:29 2019 : Debug: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default Fri Feb 15 22:33:29 2019 : Debug: (0) Post-Auth-Type REJECT { Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: calling sql (rlm_sql) Fri Feb 15 22:33:29 2019 : Debug: .query Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: literal --> .query Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND .query Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> .query Fri Feb 15 22:33:29 2019 : Debug: (0) sql: Using query template 'query' Fri Feb 15 22:33:29 2019 : Debug: rlm_sql (sql): Reserved connection (2) Fri Feb 15 22:33:29 2019 : Debug: %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: attribute --> User-Name Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> stefan Fri Feb 15 22:33:29 2019 : Debug: (0) sql: SQL-User-Name set to 'stefan' Fri Feb 15 22:33:29 2019 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: literal --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( ' Fri Feb 15 22:33:29 2019 : Debug: attribute --> SQL-User-Name Fri Feb 15 22:33:29 2019 : Debug: literal --> ', ' Fri Feb 15 22:33:29 2019 : Debug: XLAT-IF { Fri Feb 15 22:33:29 2019 : Debug: attribute --> User-Password Fri Feb 15 22:33:29 2019 : Debug: } Fri Feb 15 22:33:29 2019 : Debug: XLAT-ELSE { Fri Feb 15 22:33:29 2019 : Debug: attribute --> CHAP-Password Fri Feb 15 22:33:29 2019 : Debug: } Fri Feb 15 22:33:29 2019 : Debug: literal --> ', ' Fri Feb 15 22:33:29 2019 : Debug: attribute --> Packet-Type Fri Feb 15 22:33:29 2019 : Debug: literal --> ', ' Fri Feb 15 22:33:29 2019 : Debug: percent --> S Fri Feb 15 22:33:29 2019 : Debug: literal --> ') Fri Feb 15 22:33:29 2019 : Debug: (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Fri Feb 15 22:33:29 2019 : Debug: (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'stefan', 'frankfurt', 'Access-Reject', '2019-02-15 22:33:29') Fri Feb 15 22:33:29 2019 : Debug: (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'stefan', 'frankfurt', 'Access-Reject', '2019-02-15 22:33:29') Fri Feb 15 22:33:29 2019 : Debug: (0) sql: SQL query returned: success Fri Feb 15 22:33:29 2019 : Debug: (0) sql: 1 record(s) updated Fri Feb 15 22:33:29 2019 : Debug: rlm_sql (sql): Released connection (2) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: returned from sql (rlm_sql) Fri Feb 15 22:33:29 2019 : Debug: (0) [sql] = ok Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) Fri Feb 15 22:33:29 2019 : Debug: %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: Parsed xlat tree: Fri Feb 15 22:33:29 2019 : Debug: attribute --> User-Name Fri Feb 15 22:33:29 2019 : Debug: (0) attr_filter.access_reject: EXPAND %{User-Name} Fri Feb 15 22:33:29 2019 : Debug: (0) attr_filter.access_reject: --> stefan Fri Feb 15 22:33:29 2019 : Debug: (0) attr_filter.access_reject: Matched entry DEFAULT at line 11 Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) Fri Feb 15 22:33:29 2019 : Debug: (0) [attr_filter.access_reject] = updated Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: calling eap (rlm_eap) Fri Feb 15 22:33:29 2019 : Debug: (0) eap: Request didn't contain an EAP-Message, not inserting EAP-Failure Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: returned from eap (rlm_eap) Fri Feb 15 22:33:29 2019 : Debug: (0) [eap] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) policy remove_reply_message_if_eap { Fri Feb 15 22:33:29 2019 : Debug: (0) if (&reply:EAP-Message && &reply:Reply-Message) { Fri Feb 15 22:33:29 2019 : Debug: (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Fri Feb 15 22:33:29 2019 : Debug: (0) else { Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: calling noop (rlm_always) Fri Feb 15 22:33:29 2019 : Debug: (0) modsingle[post-auth]: returned from noop (rlm_always) Fri Feb 15 22:33:29 2019 : Debug: (0) [noop] = noop Fri Feb 15 22:33:29 2019 : Debug: (0) } # else = noop Fri Feb 15 22:33:29 2019 : Debug: (0) } # policy remove_reply_message_if_eap = noop Fri Feb 15 22:33:29 2019 : Debug: (0) } # Post-Auth-Type REJECT = updated Fri Feb 15 22:33:29 2019 : Debug: (0) Delaying response for 1.000000 seconds Fri Feb 15 22:33:29 2019 : Debug: Waking up in 0.3 seconds. Fri Feb 15 22:33:29 2019 : Debug: Waking up in 0.6 seconds. Fri Feb 15 22:33:30 2019 : Debug: (0) Sending delayed response Fri Feb 15 22:33:30 2019 : Debug: (0) Sent Access-Reject Id 109 from 127.0.0.1:1812 to 127.0.0.1:47161 length 20 Fri Feb 15 22:33:30 2019 : Debug: Waking up in 3.9 seconds. Fri Feb 15 22:33:34 2019 : Debug: (0) Cleaning up request packet ID 109 with timestamp +11 Fri Feb 15 22:33:34 2019 : Info: Ready to process requests ------------------------------ end trace ------------------------------------- server default { listen { type = auth ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { ipaddr = * port = 0 type = acct limit { } } listen { type = auth port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { ipv6addr = :: port = 0 type = acct limit { } } authorize { filter_username preprocess chap mschap digest suffix eap { ok = return } files -sql -ldap expiration logintime pap } authenticate { Auth-Type PAP { pap } Auth-Type CHAP { chap } Auth-Type MS-CHAP { mschap } mschap digest eap } preacct { preprocess acct_unique suffix files } accounting { detail unix -sql exec attr_filter.accounting_response } session { } post-auth { update { &reply: += &session-state: } -sql exec remove_reply_message_if_eap Post-Auth-Type REJECT { -sql attr_filter.access_reject eap remove_reply_message_if_eap } Post-Auth-Type Challenge { } } pre-proxy { } post-proxy { eap } } ---------------------- end setting file ----------------------

2 2

iOS SSL issue
by Mankomal Singh 15 Feb '19

15 Feb '19

Hi, So I got everything working, and am able to run TLS in my android phone but when I try thru my iPhone or my MacBook I get SSL error on RADIUS debug. Amazingly same certificate work on my android phone without any issues. Can someone share what could be the issue? A snippet of the error: *(140) eap_tls: ERROR: TLS_accept: Failed in SSLv3 read client certificate A* *(140) eap_tls: ERROR: Failed in __FUNCTION__ (SSL_read): error:140940E5:SSL routines:ssl3_read_bytes:ssl handshake failure* *(140) eap_tls: ERROR: System call (I/O) error (-1)* *(140) eap_tls: ERROR: TLS receive handshake failed during operation* *(140) eap_tls: ERROR: [eaptls process] = fail* *(140) eap: ERROR: Failed continuing EAP TLS (13) session. EAP sub-module failed* Complete EAP debug from failed devices: (156) Received Access-Request Id 238 from 103.46.239.184:36499 to 192.168.253.6:1812 length 226 (156) Service-Type = Framed-User (156) Framed-MTU = 1400 (156) User-Name = "macbook" (156) NAS-Port-Id = "wlan1" (156) NAS-Port-Type = Wireless-802.11 (156) Acct-Session-Id = "8220002d" (156) Acct-Multi-Session-Id = "CC-2D-E0-39-24-A6-B8-C1-11-D1-4D-50-82-20-00-00-00-00-00-2D" (156) Calling-Station-Id = "B8-C1-11-D1-4D-50" (156) Called-Station-Id = "CC-2D-E0-39-24-A6:THIS IS A TEST" (156) EAP-Message = 0x0200000c016d6163626f6f6b (156) Message-Authenticator = 0x9b1b6d0c79559268e6cfb2a0cbe5240d (156) NAS-Identifier = "MikroTik" (156) NAS-IP-Address = 192.168.88.2 (156) # Executing section authorize from file /etc/raddb/sites-enabled/default (156) authorize { (156) policy filter_username { (156) if (&User-Name) { (156) if (&User-Name) -> TRUE (156) if (&User-Name) { (156) if (&User-Name =~ / /) { (156) if (&User-Name =~ / /) -> FALSE (156) if (&User-Name =~ /@[^@]*@/ ) { (156) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (156) if (&User-Name =~ /\.\./ ) { (156) if (&User-Name =~ /\.\./ ) -> FALSE (156) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (156) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (156) if (&User-Name =~ /\.$/) { (156) if (&User-Name =~ /\.$/) -> FALSE (156) if (&User-Name =~ /(a)\./) { (156) if (&User-Name =~ /(a)\./) -> FALSE (156) } # if (&User-Name) = notfound (156) } # policy filter_username = notfound (156) [preprocess] = ok (156) eap: Peer sent EAP Response (code 2) ID 0 length 12 (156) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (156) [eap] = ok (156) } # authorize = ok (156) Found Auth-Type = eap (156) # Executing group from file /etc/raddb/sites-enabled/default (156) authenticate { (156) eap: Peer sent packet with method EAP Identity (1) (156) eap: Calling submodule eap_tls to process data (156) eap_tls: Initiating new EAP-TLS session (156) eap_tls: Setting verify mode to require certificate from client (156) eap_tls: [eaptls start] = request (156) eap: Sending EAP Request (code 1) ID 1 length 6 (156) eap: EAP session adding &reply:State = 0xccf8f142ccf9fce7 (156) [eap] = handled (156) } # authenticate = handled (156) Using Post-Auth-Type Challenge (156) # Executing group from file /etc/raddb/sites-enabled/default (156) Challenge { ... } # empty sub-section is ignored (156) Sent Access-Challenge Id 238 from 192.168.253.6:1812 to 103.46.239.184:36499 length 0 (156) EAP-Message = 0x010100060d20 (156) Message-Authenticator = 0x00000000000000000000000000000000 (156) State = 0xccf8f142ccf9fce75307e48862cef384 (156) Finished request Waking up in 4.9 seconds. (157) Received Access-Request Id 239 from 103.46.239.184:40285 to 192.168.253.6:1812 length 393 (157) Service-Type = Framed-User (157) Framed-MTU = 1400 (157) User-Name = "macbook" (157) State = 0xccf8f142ccf9fce75307e48862cef384 (157) NAS-Port-Id = "wlan1" (157) NAS-Port-Type = Wireless-802.11 (157) Acct-Session-Id = "8220002d" (157) Acct-Multi-Session-Id = "CC-2D-E0-39-24-A6-B8-C1-11-D1-4D-50-82-20-00-00-00-00-00-2D" (157) Calling-Station-Id = "B8-C1-11-D1-4D-50" (157) Called-Station-Id = "CC-2D-E0-39-24-A6:THIS IS A TEST" (157) EAP-Message = 0x020100a10d800000009716030300920100008e03035c66eda3b9189d8cb5e4f5d1b7da29789b4f95dc78ef817aeb5462abc249b93100002c00ffc02cc02bc024c023c00ac009c008c030c02fc028c027c014c013c012009d009c003d003c0035002f000a01000039000a00080006001700180019000b00 (157) Message-Authenticator = 0xf775fc6bc1a0190eb8997ecbcbb51f4f (157) NAS-Identifier = "MikroTik" (157) NAS-IP-Address = 192.168.88.2 (157) session-state: No cached attributes (157) # Executing section authorize from file /etc/raddb/sites-enabled/default (157) authorize { (157) policy filter_username { (157) if (&User-Name) { (157) if (&User-Name) -> TRUE (157) if (&User-Name) { (157) if (&User-Name =~ / /) { (157) if (&User-Name =~ / /) -> FALSE (157) if (&User-Name =~ /@[^@]*@/ ) { (157) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (157) if (&User-Name =~ /\.\./ ) { (157) if (&User-Name =~ /\.\./ ) -> FALSE (157) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (157) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (157) if (&User-Name =~ /\.$/) { (157) if (&User-Name =~ /\.$/) -> FALSE (157) if (&User-Name =~ /(a)\./) { (157) if (&User-Name =~ /(a)\./) -> FALSE (157) } # if (&User-Name) = notfound (157) } # policy filter_username = notfound (157) [preprocess] = ok (157) eap: Peer sent EAP Response (code 2) ID 1 length 161 (157) eap: No EAP Start, assuming it's an on-going EAP conversation (157) [eap] = updated (157) sql: EXPAND %{User-Name} (157) sql: --> macbook (157) sql: SQL-User-Name set to 'macbook' rlm_sql (sql): Reserved connection (60) (157) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (157) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (157) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (157) sql: User found in radcheck table (157) sql: Conditional check items matched, merging assignment check items (157) sql: Auth-Type := eap (157) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (157) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id (157) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id *(157) sql: WARNING: Cannot do check groups when group_membership_query is not set* rlm_sql (sql): Released connection (60) *Need 7 more connections to reach 10 spares* *rlm_sql (sql): Opening additional connection (63), 1 of 29 pending slots used* rlm_sql_mysql: Starting connect to MySQL server rlm_sql_mysql: Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.43, protocol version 10 (157) [sql] = ok (157) if (notfound) { (157) if (notfound) -> FALSE (157) [expiration] = noop (157) [logintime] = noop (157) [pap] = noop (157) } # authorize = updated (157) Found Auth-Type = eap (157) # Executing group from file /etc/raddb/sites-enabled/default (157) authenticate { (157) eap: Expiring EAP session with state 0xccf8f142ccf9fce7 (157) eap: Finished EAP session with state 0xccf8f142ccf9fce7 (157) eap: Previous EAP request found for state 0xccf8f142ccf9fce7, released from the list (157) eap: Peer sent packet with method EAP TLS (13) (157) eap: Calling submodule eap_tls to process data (157) eap_tls: Continuing EAP-TLS (157) eap_tls: Peer indicated complete TLS record size will be 151 bytes (157) eap_tls: Got complete TLS record (151 bytes) (157) eap_tls: [eaptls verify] = length included (157) eap_tls: (other): before/accept initialization (157) eap_tls: TLS_accept: before/accept initialization (157) eap_tls: <<< recv TLS 1.2 [length 0092] (157) eap_tls: TLS_accept: SSLv3 read client hello A (157) eap_tls: >>> send TLS 1.2 [length 0039] (157) eap_tls: TLS_accept: SSLv3 write server hello A (157) eap_tls: >>> send TLS 1.2 [length 06ee] (157) eap_tls: TLS_accept: SSLv3 write certificate A (157) eap_tls: >>> send TLS 1.2 [length 00cd] (157) eap_tls: TLS_accept: SSLv3 write key exchange A (157) eap_tls: >>> send TLS 1.2 [length 00a5] (157) eap_tls: TLS_accept: SSLv3 write certificate request A (157) eap_tls: TLS_accept: SSLv3 flush data (157) eap_tls: TLS_accept: Need to read more data: SSLv3 read client certificate A (157) eap_tls: TLS_accept: Need to read more data: SSLv3 read client certificate A (157) eap_tls: In SSL Handshake Phase (157) eap_tls: In SSL Accept mode (157) eap_tls: [eaptls process] = handled (157) eap: Sending EAP Request (code 1) ID 2 length 1024 (157) eap: EAP session adding &reply:State = 0xccf8f142cdfafce7 (157) [eap] = handled (157) } # authenticate = handled (157) Using Post-Auth-Type Challenge (157) # Executing group from file /etc/raddb/sites-enabled/default (157) Challenge { ... } # empty sub-section is ignored (157) Sent Access-Challenge Id 239 from 192.168.253.6:1812 to 103.46.239.184:40285 length 0 (157) EAP-Message = 0x010204000dc0000008ad160303003902000035030368fd206e3ef60d7fd094ee6184fa23ad9edd6bc23b529f88b11669a0e088a95700c03000000dff01000100000b00040300010216030306ee0b0006ea0006e70003a03082039c30820305a003020102020101300d06092a864886f70d010105050030 (157) Message-Authenticator = 0x00000000000000000000000000000000 (157) State = 0xccf8f142cdfafce75307e48862cef384 (157) Finished request Waking up in 4.9 seconds. (158) Received Access-Request Id 240 from 103.46.239.184:53647 to 192.168.253.6:1812 length 238 (158) Service-Type = Framed-User (158) Framed-MTU = 1400 (158) User-Name = "macbook" (158) State = 0xccf8f142cdfafce75307e48862cef384 (158) NAS-Port-Id = "wlan1" (158) NAS-Port-Type = Wireless-802.11 (158) Acct-Session-Id = "8220002d" (158) Acct-Multi-Session-Id = "CC-2D-E0-39-24-A6-B8-C1-11-D1-4D-50-82-20-00-00-00-00-00-2D" (158) Calling-Station-Id = "B8-C1-11-D1-4D-50" (158) Called-Station-Id = "CC-2D-E0-39-24-A6:THIS IS A TEST" (158) EAP-Message = 0x020200060d00 (158) Message-Authenticator = 0xb397d9cf688e3c16bfacd51e63ee0677 (158) NAS-Identifier = "MikroTik" (158) NAS-IP-Address = 192.168.88.2 (158) session-state: No cached attributes (158) # Executing section authorize from file /etc/raddb/sites-enabled/default (158) authorize { (158) policy filter_username { (158) if (&User-Name) { (158) if (&User-Name) -> TRUE (158) if (&User-Name) { (158) if (&User-Name =~ / /) { (158) if (&User-Name =~ / /) -> FALSE (158) if (&User-Name =~ /@[^@]*@/ ) { (158) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (158) if (&User-Name =~ /\.\./ ) { (158) if (&User-Name =~ /\.\./ ) -> FALSE (158) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (158) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (158) if (&User-Name =~ /\.$/) { (158) if (&User-Name =~ /\.$/) -> FALSE (158) if (&User-Name =~ /(a)\./) { (158) if (&User-Name =~ /(a)\./) -> FALSE (158) } # if (&User-Name) = notfound (158) } # policy filter_username = notfound (158) [preprocess] = ok (158) eap: Peer sent EAP Response (code 2) ID 2 length 6 (158) eap: No EAP Start, assuming it's an on-going EAP conversation (158) [eap] = updated (158) sql: EXPAND %{User-Name} (158) sql: --> macbook (158) sql: SQL-User-Name set to 'macbook' rlm_sql (sql): Reserved connection (62) (158) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (158) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (158) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (158) sql: User found in radcheck table (158) sql: Conditional check items matched, merging assignment check items (158) sql: Auth-Type := eap (158) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (158) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id (158) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id *(158) sql: WARNING: Cannot do check groups when group_membership_query is not set* rlm_sql (sql): Released connection (62) (158) [sql] = ok (158) if (notfound) { (158) if (notfound) -> FALSE (158) [expiration] = noop (158) [logintime] = noop (158) [pap] = noop (158) } # authorize = updated (158) Found Auth-Type = eap (158) # Executing group from file /etc/raddb/sites-enabled/default (158) authenticate { (158) eap: Expiring EAP session with state 0xccf8f142cdfafce7 (158) eap: Finished EAP session with state 0xccf8f142cdfafce7 (158) eap: Previous EAP request found for state 0xccf8f142cdfafce7, released from the list (158) eap: Peer sent packet with method EAP TLS (13) (158) eap: Calling submodule eap_tls to process data (158) eap_tls: Continuing EAP-TLS (158) eap_tls: Peer ACKed our handshake fragment (158) eap_tls: [eaptls verify] = request (158) eap_tls: [eaptls process] = handled (158) eap: Sending EAP Request (code 1) ID 3 length 1024 (158) eap: EAP session adding &reply:State = 0xccf8f142cefbfce7 (158) [eap] = handled (158) } # authenticate = handled (158) Using Post-Auth-Type Challenge (158) # Executing group from file /etc/raddb/sites-enabled/default (158) Challenge { ... } # empty sub-section is ignored (158) Sent Access-Challenge Id 240 from 192.168.253.6:1812 to 103.46.239.184:53647 length 0 (158) EAP-Message = 0x010304000dc0000008ad02a6a003020102020900b184f1d60648f80a300d06092a864886f70d01010b05003073310b300906035504061302494e310b3009060355040813024445310e300c0603550407130544656c6869310f300d060355040a130653686f757574311230100603550403130953686f75 (158) Message-Authenticator = 0x00000000000000000000000000000000 (158) State = 0xccf8f142cefbfce75307e48862cef384 (158) Finished request Waking up in 4.8 seconds. (159) Received Access-Request Id 241 from 103.46.239.184:58701 to 192.168.253.6:1812 length 238 (159) Service-Type = Framed-User (159) Framed-MTU = 1400 (159) User-Name = "macbook" (159) State = 0xccf8f142cefbfce75307e48862cef384 (159) NAS-Port-Id = "wlan1" (159) NAS-Port-Type = Wireless-802.11 (159) Acct-Session-Id = "8220002d" (159) Acct-Multi-Session-Id = "CC-2D-E0-39-24-A6-B8-C1-11-D1-4D-50-82-20-00-00-00-00-00-2D" (159) Calling-Station-Id = "B8-C1-11-D1-4D-50" (159) Called-Station-Id = "CC-2D-E0-39-24-A6:THIS IS A TEST" (159) EAP-Message = 0x020300060d00 (159) Message-Authenticator = 0x599b7d41483b5ff646d709190859ad41 (159) NAS-Identifier = "MikroTik" (159) NAS-IP-Address = 192.168.88.2 (159) session-state: No cached attributes (159) # Executing section authorize from file /etc/raddb/sites-enabled/default (159) authorize { (159) policy filter_username { (159) if (&User-Name) { (159) if (&User-Name) -> TRUE (159) if (&User-Name) { (159) if (&User-Name =~ / /) { (159) if (&User-Name =~ / /) -> FALSE (159) if (&User-Name =~ /@[^@]*@/ ) { (159) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (159) if (&User-Name =~ /\.\./ ) { (159) if (&User-Name =~ /\.\./ ) -> FALSE (159) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (159) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (159) if (&User-Name =~ /\.$/) { (159) if (&User-Name =~ /\.$/) -> FALSE (159) if (&User-Name =~ /(a)\./) { (159) if (&User-Name =~ /(a)\./) -> FALSE (159) } # if (&User-Name) = notfound (159) } # policy filter_username = notfound (159) [preprocess] = ok (159) eap: Peer sent EAP Response (code 2) ID 3 length 6 (159) eap: No EAP Start, assuming it's an on-going EAP conversation (159) [eap] = updated (159) sql: EXPAND %{User-Name} (159) sql: --> macbook (159) sql: SQL-User-Name set to 'macbook' rlm_sql (sql): Reserved connection (61) (159) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (159) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (159) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (159) sql: User found in radcheck table (159) sql: Conditional check items matched, merging assignment check items (159) sql: Auth-Type := eap (159) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (159) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id (159) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id *(159) sql: WARNING: Cannot do check groups when group_membership_query is not set* rlm_sql (sql): Released connection (61) (159) [sql] = ok (159) if (notfound) { (159) if (notfound) -> FALSE (159) [expiration] = noop (159) [logintime] = noop (159) [pap] = noop (159) } # authorize = updated (159) Found Auth-Type = eap (159) # Executing group from file /etc/raddb/sites-enabled/default (159) authenticate { (159) eap: Expiring EAP session with state 0xccf8f142cefbfce7 (159) eap: Finished EAP session with state 0xccf8f142cefbfce7 (159) eap: Previous EAP request found for state 0xccf8f142cefbfce7, released from the list (159) eap: Peer sent packet with method EAP TLS (13) (159) eap: Calling submodule eap_tls to process data (159) eap_tls: Continuing EAP-TLS (159) eap_tls: Peer ACKed our handshake fragment (159) eap_tls: [eaptls verify] = request (159) eap_tls: [eaptls process] = handled (159) eap: Sending EAP Request (code 1) ID 4 length 203 (159) eap: EAP session adding &reply:State = 0xccf8f142cffcfce7 (159) [eap] = handled (159) } # authenticate = handled (159) Using Post-Auth-Type Challenge (159) # Executing group from file /etc/raddb/sites-enabled/default (159) Challenge { ... } # empty sub-section is ignored (159) Sent Access-Challenge Id 241 from 192.168.253.6:1812 to 103.46.239.184:58701 length 0 (159) EAP-Message = 0x010400cb0d80000008ad24a53a7915db5dc8993989d24c02cfa39af20337cc762c16030300a50d00009d03010240001e060106020603050105020503040104020403030103020303020102020203007700753073310b300906035504061302494e310b3009060355040813024445310e300c0603550407 (159) Message-Authenticator = 0x00000000000000000000000000000000 (159) State = 0xccf8f142cffcfce75307e48862cef384 (159) Finished request Waking up in 4.8 seconds. (160) Received Access-Request Id 242 from 103.46.239.184:59711 to 192.168.253.6:1812 length 249 (160) Service-Type = Framed-User (160) Framed-MTU = 1400 (160) User-Name = "macbook" (160) State = 0xccf8f142cffcfce75307e48862cef384 (160) NAS-Port-Id = "wlan1" (160) NAS-Port-Type = Wireless-802.11 (160) Acct-Session-Id = "8220002d" (160) Acct-Multi-Session-Id = "CC-2D-E0-39-24-A6-B8-C1-11-D1-4D-50-82-20-00-00-00-00-00-2D" (160) Calling-Station-Id = "B8-C1-11-D1-4D-50" (160) Called-Station-Id = "CC-2D-E0-39-24-A6:THIS IS A TEST" (160) EAP-Message = 0x020400110d800000000715030300020100 (160) Message-Authenticator = 0x0dd503fd540264a4baa68f7135caa25d (160) NAS-Identifier = "MikroTik" (160) NAS-IP-Address = 192.168.88.2 (160) session-state: No cached attributes (160) # Executing section authorize from file /etc/raddb/sites-enabled/default (160) authorize { (160) policy filter_username { (160) if (&User-Name) { (160) if (&User-Name) -> TRUE (160) if (&User-Name) { (160) if (&User-Name =~ / /) { (160) if (&User-Name =~ / /) -> FALSE (160) if (&User-Name =~ /@[^@]*@/ ) { (160) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (160) if (&User-Name =~ /\.\./ ) { (160) if (&User-Name =~ /\.\./ ) -> FALSE (160) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (160) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (160) if (&User-Name =~ /\.$/) { (160) if (&User-Name =~ /\.$/) -> FALSE (160) if (&User-Name =~ /(a)\./) { (160) if (&User-Name =~ /(a)\./) -> FALSE (160) } # if (&User-Name) = notfound (160) } # policy filter_username = notfound (160) [preprocess] = ok (160) eap: Peer sent EAP Response (code 2) ID 4 length 17 (160) eap: No EAP Start, assuming it's an on-going EAP conversation (160) [eap] = updated (160) sql: EXPAND %{User-Name} (160) sql: --> macbook (160) sql: SQL-User-Name set to 'macbook' rlm_sql (sql): Reserved connection (60) (160) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (160) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (160) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'macbook' ORDER BY id (160) sql: User found in radcheck table (160) sql: Conditional check items matched, merging assignment check items (160) sql: Auth-Type := eap (160) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (160) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id (160) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'macbook' ORDER BY id *(160) sql: WARNING: Cannot do check groups when group_membership_query is not set* rlm_sql (sql): Released connection (60) (160) [sql] = ok (160) if (notfound) { (160) if (notfound) -> FALSE (160) [expiration] = noop (160) [logintime] = noop (160) [pap] = noop (160) } # authorize = updated (160) Found Auth-Type = eap (160) # Executing group from file /etc/raddb/sites-enabled/default (160) authenticate { (160) eap: Expiring EAP session with state 0xccf8f142cffcfce7 (160) eap: Finished EAP session with state 0xccf8f142cffcfce7 (160) eap: Previous EAP request found for state 0xccf8f142cffcfce7, released from the list (160) eap: Peer sent packet with method EAP TLS (13) (160) eap: Calling submodule eap_tls to process data (160) eap_tls: Continuing EAP-TLS (160) eap_tls: Peer indicated complete TLS record size will be 7 bytes (160) eap_tls: Got complete TLS record (7 bytes) (160) eap_tls: [eaptls verify] = length included (160) eap_tls: <<< recv TLS 1.2 [length 0002] *(160) eap_tls: ERROR: TLS_accept: Failed in SSLv3 read client certificate A* *(160) eap_tls: ERROR: Failed in __FUNCTION__ (SSL_read): error:140940E5:SSL routines:ssl3_read_bytes:ssl handshake failure* *(160) eap_tls: ERROR: System call (I/O) error (-1)* *(160) eap_tls: ERROR: TLS receive handshake failed during operation* *(160) eap_tls: ERROR: [eaptls process] = fail* *(160) eap: ERROR: Failed continuing EAP TLS (13) session. EAP sub-module failed* (160) eap: Sending EAP Failure (code 4) ID 4 length 4 (160) eap: Failed in EAP select (160) [eap] = invalid (160) } # authenticate = invalid (160) Failed to authenticate the user (160) Using Post-Auth-Type Reject (160) # Executing group from file /etc/raddb/sites-enabled/default (160) Post-Auth-Type REJECT { (160) sql: EXPAND .query (160) sql: --> .query (160) sql: Using query template 'query' rlm_sql (sql): Reserved connection (63) (160) sql: EXPAND %{User-Name} (160) sql: --> macbook (160) sql: SQL-User-Name set to 'macbook' (160) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (160) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'macbook', '', 'Access-Reject', '2019-02-15 22:36:48.754856') (160) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'macbook', '', 'Access-Reject', '2019-02-15 22:36:48.754856') (160) sql: SQL query returned: success (160) sql: 1 record(s) updated rlm_sql (sql): Released connection (63) (160) [sql] = ok (160) attr_filter.access_reject: EXPAND %{User-Name} (160) attr_filter.access_reject: --> macbook (160) attr_filter.access_reject: Matched entry DEFAULT at line 11 (160) [attr_filter.access_reject] = updated (160) [eap] = noop (160) policy remove_reply_message_if_eap { (160) if (&reply:EAP-Message && &reply:Reply-Message) { (160) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (160) else { (160) [noop] = noop (160) } # else = noop (160) } # policy remove_reply_message_if_eap = noop (160) } # Post-Auth-Type REJECT = updated (160) Delaying response for 1.000000 seconds Waking up in 0.3 seconds. Waking up in 0.6 seconds. (160) Sending delayed response (160) Sent Access-Reject Id 242 from 192.168.253.6:1812 to 103.46.239.184:59711 length 44 (160) EAP-Message = 0x04040004 (160) Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 3.8 seconds. (156) Cleaning up request packet ID 238 with timestamp +5619 (157) Cleaning up request packet ID 239 with timestamp +5619 (158) Cleaning up request packet ID 240 with timestamp +5619 (159) Cleaning up request packet ID 241 with timestamp +5619 (160) Cleaning up request packet ID 242 with timestamp +5619 *Ready to process requests* Cheers MK Singh +91-9910416231 www.shouut.com

2 1

FreeRADIUS with custom multi-factor authentication
by Clint Lord 15 Feb '19

15 Feb '19

We are evaluating FreeRADIUS as a possible solution but we have a very specific authentication workflow and aren’t sure if FreeRADIUS will fit our needs. We’ve searched the documentation for insights into how we might accomplish our goals, but haven’t seen anything that quite matches up. Here is our workflow: 1. The user enters their username and password. 2. The system calls a web service to validate the username and password. 3. If the username and password are valid, and the user’s account has MFA enabled: a. The MFA method is executed (ex. OTP is sent via SMS message) b. The system sends the user a message asking them to enter the OTP and allows them to submit the value. c. The system validates their response by calling another web service. d. If the response is invalid the system sends another message informing them of the failure and allows them to respond again (a few times). All of the account data, username/password authentication and MFA processing is done behind web services, we just need FreeRADIUS to allow us to go through the multiple request and response steps as we call these web services. We thought we might be able to use rlm_python or rlm_perl to accomplish this, but we are only seeing simple “func_authenticate” implementations and can’t see how we can facilitate this back and forth communication with the user. All we are asking are some pointers or general guidance so we can continue our research and determine if FreeRADIUS will meet our needs. Thank you for any insights, guidance, links that might help. Clint Lord The Voodoo Cube

6 12

EAP-TLS - How to log TLS-Client-Cert-* attributes from expired certificates
by Andreas Gryphius 15 Feb '19

15 Feb '19

Hello freeradius user list, I have a running freeradius from the default package coming with Debian 9 stretch , which is based on version 3.0.12 . It is configured to auth only via EAP-TLS. Clients sent their certificates, no passwords and no (real) username. Accepts and Rejects work as expected. What I am not happy with is that I can not find a way to log the certificate details if a user is sending an expired certificate. For users with valid certificates I see all the values for TLS-Client-Cert-* in %{pairs:request:} in linelog . The linelog-command for successful auth is set in the post-auth{} section in sites-enabled/default . With expired client-certificates the eap module jumps direct into Post-Auth-Type REJECT {} (located within post-auth{} section) and none of the TLS-Client-Cert-* details are available (I tried with debug_all). Only Module-Failure-Message is mentioning "... expired certificate ..." and some SSL info. As all of the clients are configured to use an anonymised identity (all use the same) as the username I can not see to whom the expired certificate belongs. In debug mode it says there are TLS attributes created for an expired certificate. So there might be hope to save them for later use ... Does anyone have an idea how I can make these attributes available in linelog? This is an example what I get for an expired certificate in debug mode . Note the lines (226) eap_tls: Creating attributes from certificate OIDs I want to log the value of TLS-Client-Cert-Subject and/or TLS-Client-Cert-Common-Name. freeradius -fxx -l stdout 2>&1 | tee /tmp/freeradius_debug.log Thread 4 handling request 226, (92 handled so far) (226) Received Access-Request Id 110 from 10.1.2.3:32847 to 10.100.0.1:1812 length 554 (226) User-Name = "anonymous(a)example.org" (226) NAS-IP-Address = 192.168.1.12 (226) NAS-Identifier = "0418d67042af" (226) NAS-Port = 0 (226) Called-Station-Id = "04-18-D6-78-55-E1:wifi-radius" (226) Calling-Station-Id = "60-36-DD-7C-E2-DC" (226) Framed-MTU = 1400 (226) NAS-Port-Type = Wireless-802.11 (226) Connect-Info = "CONNECT 0Mbps 802.11b" (226) EAP-Message = xxxxxxxxx... (226) State = 0x3aec898e31c584882f19a28945c85c1b (226) Message-Authenticator = 0x8eeb70cc5c6a84bf36523e303d207ff6 (226) session-state: No cached attributes (226) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (226) authorize { (226) policy split_username_nai { (226) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { (226) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) -> TRUE (226) if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) { (226) update request { (226) EXPAND %{1} (226) --> anonymous (226) &Stripped-User-Name := anonymous (226) EXPAND %{3} (226) --> example.org (226) &Stripped-User-Domain = example.org (226) } # update request = noop (226) [updated] = updated (226) } # if (&User-Name && (&User-Name =~ /^([^@]*)(@([-[:alnum:]]+\.[-[:alnum:].]+))?$/)) = updated (226) ... skipping else: Preceding "if" was taken (226) } # policy split_username_nai = updated (226) if (noop || !&Stripped-User-Domain) { (226) if (noop || !&Stripped-User-Domain) -> FALSE (226) if (&Stripped-User-Domain != "example.org") { (226) if (&Stripped-User-Domain != "example.org") -> FALSE (226) if ( &Stripped-User-Name !~ /otherPKI/i ) { (226) if ( &Stripped-User-Name !~ /otherPKI/i ) -> TRUE (226) if ( &Stripped-User-Name !~ /otherPKI/i ) { (226) eap: Peer sent EAP Response (code 2) ID 41 length 369 (226) eap: No EAP Start, assuming it's an on-going EAP conversation (226) [eap] = updated (226) return (226) } # if ( &Stripped-User-Name !~ /otherPKI/i ) = updated (226) } # authorize = updated (226) Found Auth-Type = eap (226) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (226) authenticate { (226) eap: Expiring EAP session with state 0x3aec898e31c58488 (226) eap: Finished EAP session with state 0x3aec898e31c58488 (226) eap: Previous EAP request found for state 0x3aec898e31c58488, released from the list (226) eap: Peer sent packet with method EAP TLS (13) (226) eap: Calling submodule eap_tls to process data (226) eap_tls: Continuing EAP-TLS (226) eap_tls: Got final TLS record fragment (363 bytes) (226) eap_tls: [eaptls verify] = ok (226) eap_tls: Done initial handshake (226) eap_tls: TLS_accept: SSLv3/TLS write server done (226) eap_tls: <<< recv TLS 1.2 [length 13a3] (226) eap_tls: Creating attributes from certificate OIDs (226) eap_tls: Creating attributes from certificate OIDs (226) eap_tls: Creating attributes from certificate OIDs (226) eap_tls: TLS-Cert-Serial := "17887d08b33e3d" (226) eap_tls: TLS-Cert-Expiration := "190709235900Z" (226) eap_tls: TLS-Cert-Subject := "/C=DE/O=Example/OU=ExampleOU/CN=Example-CA-02" (226) eap_tls: TLS-Cert-Issuer := "/C=DE/O=Example/OU=Example-PKI/CN=Example-CA-01" (226) eap_tls: TLS-Cert-Common-Name := "Example-CA-02" (226) eap_tls: TLS-Cert-Subject-Alt-Name-Email := "ca(a)example.org" (226) eap_tls: Creating attributes from certificate OIDs (226) eap_tls: TLS-Client-Cert-Serial := "1a694699888a48" (226) eap_tls: TLS-Client-Cert-Expiration := "181115121610Z" (226) eap_tls: TLS-Client-Cert-Subject := "/C=DE/ST=ExampleST/L=ExampleL/O=Example/OU=ExampleOU/CN=Expired_Example_Cert" (226) eap_tls: TLS-Client-Cert-Issuer := "/C=DE/O=Example/OU=ExampleOU/CN=Example-CA-02" (226) eap_tls: TLS-Client-Cert-Common-Name := "Expired_Example_Cert" (226) eap_tls: TLS-Client-Cert-Subject-Alt-Name-Upn := "anonymous(a)example.org" (226) eap_tls: TLS-Client-Cert-Subject-Alt-Name-Email := "gryphius(a)example.org" (226) eap_tls: ERROR: SSL says error 10 : certificate has expired (226) eap_tls: >>> send TLS 1.2 [length 0002] (226) eap_tls: ERROR: TLS Alert write:fatal:certificate expired tls: TLS_accept: Error in error (226) eap_tls: ERROR: Failed in __FUNCTION__ (SSL_read): error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed (226) eap_tls: ERROR: System call (I/O) error (-1) (226) eap_tls: ERROR: TLS receive handshake failed during operation (226) eap_tls: ERROR: [eaptls process] = fail (226) eap: ERROR: Failed continuing EAP TLS (13) session. EAP sub-module failed (226) eap: Sending EAP Failure (code 4) ID 41 length 4 (226) eap: Failed in EAP select (226) [eap] = invalid (226) } # authenticate = invalid (226) Failed to authenticate the user (226) Using Post-Auth-Type Reject (226) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (226) Post-Auth-Type REJECT { (226) if ( &Module-Failure-Message[1] =~ /expired/ ) { (226) if ( &Module-Failure-Message[1] =~ /expired/ ) -> TRUE (226) if ( &Module-Failure-Message[1] =~ /expired/ ) -> TRUE (226) if ( &Module-Failure-Message[1] =~ /expired/ ) { (226) linelog_cert_expired: EXPAND +++++ linelog_CERT-EXPIRED +++++, %{pairs:session-state:} (226) linelog_cert_expired: --> +++++ linelog_CERT-EXPIRED +++++, (226) [linelog_cert_expired] = ok (226) } # if ( &Module-Failure-Message[1] =~ /expired/ ) = ok (226) attr_filter.access_reject: EXPAND %{User-Name} (226) attr_filter.access_reject: --> anonymous(a)example.org (226) attr_filter.access_reject: Matched entry DEFAULT at line 11 (226) [attr_filter.access_reject] = updated (226) linelog_send_reject: EXPAND action = Send-REJECT, User-Name = "%{User-Name}", Acesspoint-IP = "%{NAS-IP-Address}", Endgeraet-MAC = "%{Calling-Station-Id}", Stripped-User-Name = "%{Stripped-User-Name}", Stripped-User-Domain = "%{Stripped-User-Domain}", EAP-Type = "%{EAP-Type}", Module-Failure-Message(s) = "%{Module-Failure-Message[*]}" (226) linelog_send_reject: --> action = Send-REJECT, User-Name = "anonymous(a)example.org", Acesspoint-IP = "192.168.1.12", Endgeraet-MAC = "60-36-DD-7C-E2-DC", Stripped-User-Name = "anonymous", Stripped-User-Domain = "example.org", EAP-Type = "TLS", Module-Failure-Message(s) = "eap_tls: SSL says error 10 : certificate has expired,eap_tls: TLS Alert write:fatal:certificate expired,eap_tls: Failed in __FUNCTION__ (SSL_read): error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed,eap_tls: System call (I/O) error (-1),eap_tls: TLS receive handshake failed during operation,eap_tls: [eaptls process] = fail,eap: Failed continuing EAP TLS (13) session. EAP sub-module failed" (226) [linelog_send_reject] = ok (226) } # Post-Auth-Type REJECT = updated (226) Delaying response for 1.000000 seconds Thanks, Andreas

3 4

Freeradius filter-id + FreeIPA
by Boudjoudad Abdelkader 15 Feb '19

15 Feb '19

Hello, We have a FreeIPA as domain controller and we are planing to use Freeradius as authentication for the Wireless, i configured freeradius with LDAP and i can do authentication with a domain user with the command radtest, now the network team asked me to configure freeradius to return a filter-i of the user group assigned ID, example we have user1: dn: uid=user1,cn=users,cn=accounts,dc=subdmain,dc=domain,dc=com with the group ID:gid=1471600000 I did some research on google and i found that i have to modify the file /etc/raddb/sites-enabled/default like in the link bellow but not exactly the same thing and which command i have to use get this value: FreeIPA_Freeeradius <https://stackoverflow.com/questions/43913834/freeradius-filter-id> Any suggestion please ? Thanks

1 0

EAP-TLS with user base in SQL not happening
by Mankomal Singh 15 Feb '19

15 Feb '19

Hi I am doing EAP-TLS test to authenticate only known users that are in SQL to authenticate via TLS method, how can I achieve this? can some one share me any guide on this, I have been able to achieve TLS authentication on files but not able to do so via SQL Server. My issue is that even if the user is not found in SQL it is able to authenticate via TLS Cheers MK Singh +91-9910416231 www.shouut.com

2 1

Accept user if his account expired
by mohamad buvaydanı 13 Feb '19

13 Feb '19

hello I am using freeradius v3 . I want when expired user trying to access his account the freeradius will send accept packet with new ip pool for example 'expired ' I am using this code in authorize section expiration{ userlock = 1 } if(userlock){ # Let him connect with EXPIRED pool in reply ok update reply { Reply-Message := "Your account has expired, %{User-Name} / Reason: DATE LIMIT REACHED / " Framed-Pool := "expired" } } but user still get reject , without get new ip pool I tried to insert that same code in to Post-Auth-Type REJECT section the users rejected but get new ip pool where is my error thank you

3 3

Output Memory allocation error (0xc0000017)
by Burn Zero 13 Feb '19

13 Feb '19

Hi, Freeradius server version : 3.0.17, 64bit OS : CentOS 7.2 We have setup Freeradius to authenticate users to get access to WiFi. Freeradius is connected to Active Directory servers for authentication. Recently Freeradius logged the message "NT_STATUS_ACCESS_DENIED" in the authentication logs and users were not authenticated. Additionally, I can see the below logs in Freeradius: ERROR: (3978) ntlm_auth: ERROR: Program returned code (1) and output 'NT_STATUS_NO_MEMORY: Memory allocation error (0xc0000017)' Auth: (3978) Login incorrect (ntlm_auth: Program returned code (1) and output 'NT_STATUS_NO_MEMORY: Memory allocation error (0xc0000017)') On the another day we got the same issue, same error message and in the Freeradius logs, we got: ERROR: (43458) mschap: ERROR: Program returned code (1) and output 'Memory allocation error (0xc0000017)' Auth: (43458) Login incorrect (mschap: Program returned code (1) and output 'Memory allocation error (0xc0000017)') When we rejoin the Active Directory domain, the issue gets resolved. Not sure where the issue lies. Kindly help me. Thank you. Regards, Burn Zero

2 1

Cause of relatively large retransmission-rate in radsniff output
by Fekete Tamás 13 Feb '19

13 Feb '19

Hello! I would like to ask help with understanding my radsniff output as usually I get a huge number of Access-Request retransmission rate. When I have run radsniff -W 1, I got the following output: ... Access-Request counters: Total : 66.000/s Linked : 64.000/s Unlinked : 0.000/s Access-Request latency: High : 1000.607ms Low : 0.260ms Average : 17.473ms MA : 23.723ms Access-Request retransmits & loss: RT (0) : 56.000/s ... As it can be seen above, I got 56 retransmission. It is a huge number compared to the 66 Total Access Request / sec. I checked if the RT (retransmission) value contains the loss packets and the Access-Requests which has been resent due to Access-Challenges. My result is that loss packets are separately show up in this statistics like: Access-Request retransmits & loss: Lost : 1.000/s RT (0) : 55.000/s And Access-Requests followed by Access-Challenges are not count into the Retrasmission. Here is an output from a virtual machine which was tested with eapol_test (with peap-mschapv2 method): Interface capture rate: ens3 : 0.000/s lo : 40.000/s Access-Request counters: Total : 10.000/s Linked : 10.000/s Unlinked : 0.000/s Access-Request latency: High : 6.417ms Low : 0.119ms Average : 0.949ms MA : 0.949ms Access-Accept counters: Total : 1.000/s Linked : 1.000/s Unlinked : 0.000/s Access-Accept latency: High : 0.190ms Low : 0.190ms Average : 0.190ms MA : 0.190ms Access-Challenge counters: Total : 9.000/s Linked : 9.000/s Unlinked : 0.000/s Access-Challenge latency: High : 6.417ms Low : 0.119ms Average : 1.033ms MA : 1.033ms It means that the Access-Requests followed by Access-Challenges are not evaluated like Retransmitted requests. They are counted like new Access-Requests. So my question is, do you think this retransmission rate is normal? And if not or not sure, do you have a hint or suggestion where to start the investigation? If I should use debug output of Freeradius, what is the thing I have to look in it? - Tamas Fekete

2 2