Problem EAp

Hello,I have a problem with freeradius 3.0.17 with samba 4.9.5 under debian 10.When I do thisradtest -t mschap eric.roger XXXXXXXX 127.0.0.1 0 testing123it worksSent Access-Request Id 251 from 0.0.0.0:46535 to 127.0.0.1:1812 length 136 User-Name = "eric.roger" MS-CHAP-Password = "Buckroger*1234*" NAS-IP-Address=172.16.1.232 NAS-Port = 0 Message-Authenticator = 0x00 Cleartext-Password="XXXXXXX" MS-CHAP-Challenge=0xe7b3443bc4983e22 MS-CHAP-Response=0x0001000000000000000000000000000000000000000000000000bfcdc7b44a760f05e5ce1d89ea0bc8a546bc7627fb3edd4Received Access-Accept Id 251 from 127.0.0.1:1812 to 127.0.0.1:46535 length 84 MS-CHAP-MPPE-Keys=0x0000000000000000bbee31eb54dd1eef75e78c302ccd2b09 MS-MPPE-Encryption-Policy=Encryption-Allowed MS-MPPE-Encryption-Types=RC4-40or128-bit-Allowed in Eap it does not work on android or windows 10. I post my log of freeradius -XXX I don't see the error I use the base certificates to test snakeoil before putting my own. but I don't understand the problem. the server is joined to the domain and the radtest works? thank you very much for your help and if necessary other files I can send them Thank you Eric Tue Feb 15 07:49:22 2022 : Debug: Server was built with: Tue Feb 15 07:49:22 2022 : Debug: accounting : yesTue Feb 15 07:49:22 2022 : Debug: authentication : yesTue Feb 15 07:49:22 2022 : Debug: ascend-binary-attributes : yesTue Feb 15 07:49:22 2022 : Debug: coa : yesTue Feb 15 07:49:22 2022 : Debug: control-socket : yesTue Feb 15 07:49:22 2022 : Debug: detail : yesTue Feb 15 07:49:22 2022 : Debug: dhcp : yesTue Feb 15 07:49:22 2022 : Debug: dynamic-clients : yesTue Feb 15 07:49:22 2022 : Debug: osfc2 : noTue Feb 15 07:49:22 2022 : Debug: proxy : yesTue Feb 15 07:49:22 2022 : Debug: regex-pcre : yesTue Feb 15 07:49:22 2022 : Debug: regex-posix : noTue Feb 15 07:49:22 2022 : Debug: regex-posix-extended : noTue Feb 15 07:49:22 2022 : Debug: session-management : yesTue Feb 15 07:49:22 2022 : Debug: stats : yesTue Feb 15 07:49:22 2022 : Debug: tcp : yesTue Feb 15 07:49:22 2022 : Debug: threads : yesTue Feb 15 07:49:22 2022 : Debug: tls : yesTue Feb 15 07:49:22 2022 : Debug: unlang : yesTue Feb 15 07:49:22 2022 : Debug: vmps : yesTue Feb 15 07:49:22 2022 : Debug: developer : noTue Feb 15 07:49:22 2022 : Debug: Server core libs:Tue Feb 15 07:49:22 2022 : Debug: freeradius-server : 3.0.17Tue Feb 15 07:49:22 2022 : Debug: talloc : 2.1.*Tue Feb 15 07:49:22 2022 : Debug: ssl : 1.1.1d releaseTue Feb 15 07:49:22 2022 : Debug: pcre : 8.39 2016-06-14Tue Feb 15 07:49:22 2022 : Debug: Endianness:Tue Feb 15 07:49:22 2022 : Debug: littleTue Feb 15 07:49:22 2022 : Debug: Compilation flags:Tue Feb 15 07:49:22 2022 : Debug: cppflags : -Wdate-time -D_FORTIFY_SOURCE=2Tue Feb 15 07:49:22 2022 : 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-RXCWcb/freeradius-3.0.17+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=1Tue Feb 15 07:49:22 2022 : Debug: ldflags : -Wl,-z,relro -Wl,-z,nowTue Feb 15 07:49:22 2022 : Debug: libs : -lcrypto -lssl -ltalloc -lpcre -lcap -lnsl -lresolv -ldl -lpthread -lreadlineTue Feb 15 07:49:22 2022 : Debug: Tue Feb 15 07:49:22 2022 : Info: FreeRADIUS Version 3.0.17Tue Feb 15 07:49:22 2022 : Info: Copyright (C) 1999-2017 The FreeRADIUS server project and contributorsTue Feb 15 07:49:22 2022 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR ATue Feb 15 07:49:22 2022 : Info: PARTICULAR PURPOSETue Feb 15 07:49:22 2022 : Info: You may redistribute copies of FreeRADIUS under the terms of theTue Feb 15 07:49:22 2022 : Info: GNU General Public LicenseTue Feb 15 07:49:22 2022 : Info: For more information about these matters, see the file named COPYRIGHTTue Feb 15 07:49:22 2022 : Info: Starting - reading configuration files ...Tue Feb 15 07:49:22 2022 : Debug: including dictionary file /usr/share/freeradius/dictionaryTue Feb 15 07:49:22 2022 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcpTue Feb 15 07:49:22 2022 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqpTue Feb 15 07:49:22 2022 : Debug: including dictionary file /etc/freeradius/3.0/dictionaryTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/radiusd.confTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/proxy.confTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/clients.confTue Feb 15 07:49:22 2022 : Debug: including files in directory /etc/freeradius/3.0/mods-enabled/Tue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detailTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/linelogTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/digestTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/filesTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/papTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/preprocessTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/mschapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/logintimeTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sohTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/echoTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/chapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/execTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clientsTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/sradutmpTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/radutmpTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unixTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/passwdTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/exprTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/replicateTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_authTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/utf8Tue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/eapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/cache_eapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/ldapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/expirationTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/mods-enabled/unpackTue Feb 15 07:49:22 2022 : Debug: including files in directory /etc/freeradius/3.0/policy.d/Tue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/cuiTue Feb 15 07:49:22 2022 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSETue Feb 15 07:49:22 2022 : Debug: OPTIMIZING (no == yes) --> FALSETue Feb 15 07:49:22 2022 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSETue Feb 15 07:49:22 2022 : Debug: OPTIMIZING (no == yes) --> FALSETue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/operator-nameTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/controlTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/debugTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-idsTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/abfab-trTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/filterTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/dhcpTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/accountingTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/eapTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/policy.d/canonicalizationTue Feb 15 07:49:22 2022 : Debug: including files in directory /etc/freeradius/3.0/sites-enabled/Tue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/inner-tunnelTue Feb 15 07:49:22 2022 : Debug: including configuration file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:22 2022 : Debug: main {Tue Feb 15 07:49:22 2022 : Debug: security {Tue Feb 15 07:49:22 2022 : Debug: user = "freerad"Tue Feb 15 07:49:22 2022 : Debug: group = "freerad"Tue Feb 15 07:49:22 2022 : Debug: allow_core_dumps = noTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: name = "freeradius"Tue Feb 15 07:49:22 2022 : Debug: prefix = "/usr"Tue Feb 15 07:49:22 2022 : Debug: localstatedir = "/var"Tue Feb 15 07:49:22 2022 : Debug: logdir = "/var/log/freeradius"Tue Feb 15 07:49:22 2022 : Debug: run_dir = "/var/run/freeradius"Tue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[69]: The item 'certdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[232]: The item 'max_requests' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[483]: The item 'proxy_requests' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: main {Tue Feb 15 07:49:22 2022 : Debug: name = "freeradius"Tue Feb 15 07:49:22 2022 : Debug: prefix = "/usr"Tue Feb 15 07:49:22 2022 : Debug: localstatedir = "/var"Tue Feb 15 07:49:22 2022 : Debug: sbindir = "/usr/sbin"Tue Feb 15 07:49:22 2022 : Debug: logdir = "/var/log/freeradius"Tue Feb 15 07:49:22 2022 : Debug: run_dir = "/var/run/freeradius"Tue Feb 15 07:49:22 2022 : Debug: libdir = "/usr/lib/freeradius"Tue Feb 15 07:49:22 2022 : Debug: radacctdir = "/var/log/freeradius/radacct"Tue Feb 15 07:49:22 2022 : Debug: hostname_lookups = noTue Feb 15 07:49:22 2022 : Debug: max_request_time = 30Tue Feb 15 07:49:22 2022 : Debug: cleanup_delay = 5Tue Feb 15 07:49:22 2022 : Debug: max_requests = 16384Tue Feb 15 07:49:22 2022 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"Tue Feb 15 07:49:22 2022 : Debug: checkrad = "/usr/sbin/checkrad"Tue Feb 15 07:49:22 2022 : Debug: debug_level = 0Tue Feb 15 07:49:22 2022 : Debug: proxy_requests = yesTue Feb 15 07:49:22 2022 : Debug: log {Tue Feb 15 07:49:22 2022 : Debug: stripped_names = noTue Feb 15 07:49:22 2022 : Debug: auth = noTue Feb 15 07:49:22 2022 : Debug: auth_badpass = noTue Feb 15 07:49:22 2022 : Debug: auth_goodpass = noTue Feb 15 07:49:22 2022 : Debug: colourise = yesTue Feb 15 07:49:22 2022 : Debug: msg_denied = "You are already logged in - access denied"Tue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[285]: The item 'file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: resources {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: security {Tue Feb 15 07:49:22 2022 : Debug: max_attributes = 200Tue Feb 15 07:49:22 2022 : Debug: reject_delay = 1.000000Tue Feb 15 07:49:22 2022 : Debug: status_server = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[69]: The item 'certdir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: radiusd: #### Loading Realms and Home Servers ####Tue Feb 15 07:49:22 2022 : Debug: proxy server {Tue Feb 15 07:49:22 2022 : Debug: retry_delay = 5Tue Feb 15 07:49:22 2022 : Debug: retry_count = 3Tue Feb 15 07:49:22 2022 : Debug: default_fallback = noTue Feb 15 07:49:22 2022 : Debug: dead_time = 120Tue Feb 15 07:49:22 2022 : Debug: wake_all_if_all_dead = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: home_server localhost {Tue Feb 15 07:49:22 2022 : Debug: ipaddr = 127.0.0.1Tue Feb 15 07:49:22 2022 : Debug: port = 1812Tue Feb 15 07:49:22 2022 : Debug: type = "auth"Tue Feb 15 07:49:22 2022 : Debug: secret = "testing123"Tue Feb 15 07:49:22 2022 : Debug: response_window = 20.000000Tue Feb 15 07:49:22 2022 : Debug: response_timeouts = 1Tue Feb 15 07:49:22 2022 : Debug: max_outstanding = 65536Tue Feb 15 07:49:22 2022 : Debug: zombie_period = 40Tue Feb 15 07:49:22 2022 : Debug: status_check = "status-server"Tue Feb 15 07:49:22 2022 : Debug: ping_interval = 30Tue Feb 15 07:49:22 2022 : Debug: check_interval = 30Tue Feb 15 07:49:22 2022 : Debug: check_timeout = 4Tue Feb 15 07:49:22 2022 : Debug: num_answers_to_alive = 3Tue Feb 15 07:49:22 2022 : Debug: revive_interval = 120Tue Feb 15 07:49:22 2022 : Debug: limit {Tue Feb 15 07:49:22 2022 : Debug: max_connections = 16Tue Feb 15 07:49:22 2022 : Debug: max_requests = 0Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 0Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: coa {Tue Feb 15 07:49:22 2022 : Debug: irt = 2Tue Feb 15 07:49:22 2022 : Debug: mrt = 16Tue Feb 15 07:49:22 2022 : Debug: mrc = 5Tue Feb 15 07:49:22 2022 : Debug: mrd = 30Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: home_server_pool my_auth_failover {Tue Feb 15 07:49:22 2022 : Debug: type = fail-overTue Feb 15 07:49:22 2022 : Debug: home_server = localhostTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: realm example.com {Tue Feb 15 07:49:22 2022 : Debug: auth_pool = my_auth_failoverTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: realm LOCAL {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: realm lyceeader.eu {Tue Feb 15 07:49:22 2022 : Debug: authhost = LOCALTue Feb 15 07:49:22 2022 : Debug: accthost = LOCALTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: realm DEFAULT {Tue Feb 15 07:49:22 2022 : Debug: nostripTue Feb 15 07:49:22 2022 : Debug: authhost = LOCALTue Feb 15 07:49:22 2022 : Debug: accthost = LOCALTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: radiusd: #### Loading Clients ####Tue Feb 15 07:49:22 2022 : Debug: client localhost {Tue Feb 15 07:49:22 2022 : Debug: ipaddr = 127.0.0.1Tue Feb 15 07:49:22 2022 : Debug: require_message_authenticator = noTue Feb 15 07:49:22 2022 : Debug: secret = "testing123"Tue Feb 15 07:49:22 2022 : Debug: nas_type = "other"Tue Feb 15 07:49:22 2022 : Debug: proto = "*"Tue Feb 15 07:49:22 2022 : Debug: limit {Tue Feb 15 07:49:22 2022 : Debug: max_connections = 16Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32Tue Feb 15 07:49:22 2022 : Debug: client private-pfsense {Tue Feb 15 07:49:22 2022 : Debug: ipaddr = 172.16.1.1/24Tue Feb 15 07:49:22 2022 : Debug: require_message_authenticator = noTue Feb 15 07:49:22 2022 : Debug: secret = "aderader"Tue Feb 15 07:49:22 2022 : Debug: limit {Tue Feb 15 07:49:22 2022 : Debug: max_connections = 16Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Adding client 172.16.1.0/24 (172.16.1.0) to prefix tree 24Tue Feb 15 07:49:22 2022 : Debug: client lan251 {Tue Feb 15 07:49:22 2022 : Debug: ipaddr = 172.16.251.251/24Tue Feb 15 07:49:22 2022 : Debug: require_message_authenticator = noTue Feb 15 07:49:22 2022 : Debug: secret = "aderader"Tue Feb 15 07:49:22 2022 : Debug: limit {Tue Feb 15 07:49:22 2022 : Debug: max_connections = 16Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Adding client 172.16.251.0/24 (172.16.251.0) to prefix tree 24Tue Feb 15 07:49:22 2022 : Debug: client lan252 {Tue Feb 15 07:49:22 2022 : Debug: ipaddr = 172.16.252.252/24Tue Feb 15 07:49:22 2022 : Debug: require_message_authenticator = noTue Feb 15 07:49:22 2022 : Debug: secret = "aderader"Tue Feb 15 07:49:22 2022 : Debug: limit {Tue Feb 15 07:49:22 2022 : Debug: max_connections = 16Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Adding client 172.16.252.0/24 (172.16.252.0) to prefix tree 24Tue Feb 15 07:49:22 2022 : Info: Debugger not attachedTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = mschapTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = eapTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = PAPTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = CHAPTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = MS-CHAPTue Feb 15 07:49:22 2022 : Debug: # Creating Auth-Type = digestTue Feb 15 07:49:22 2022 : Debug: radiusd: #### Instantiating modules ####Tue Feb 15 07:49:22 2022 : Debug: modules {Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_detail, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_detailTue Feb 15 07:49:22 2022 : Debug: # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detailTue Feb 15 07:49:22 2022 : Debug: detail {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"Tue Feb 15 07:49:22 2022 : Debug: header = "%t"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: locking = noTue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: log_packet_header = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_linelog with path: /usr/lib/freeradius/rlm_linelog.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_linelog, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_linelogTue Feb 15 07:49:22 2022 : Debug: # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelogTue Feb 15 07:49:22 2022 : Debug: linelog {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/linelog"Tue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: syslog_severity = "info"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: format = "This is a log message for %{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelogTue Feb 15 07:49:22 2022 : Debug: linelog log_accounting {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/linelog-accounting"Tue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: syslog_severity = "info"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: format = ""Tue Feb 15 07:49:22 2022 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_digest with path: /usr/lib/freeradius/rlm_digest.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_digest, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_digestTue Feb 15 07:49:22 2022 : Debug: # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digestTue Feb 15 07:49:22 2022 : Debug: Loading rlm_files with path: /usr/lib/freeradius/rlm_files.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_files, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_filesTue Feb 15 07:49:22 2022 : Debug: # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/filesTue Feb 15 07:49:22 2022 : Debug: files {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/files/authorize"Tue Feb 15 07:49:22 2022 : Debug: acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting"Tue Feb 15 07:49:22 2022 : Debug: preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_pap, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_papTue Feb 15 07:49:22 2022 : Debug: # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/papTue Feb 15 07:49:22 2022 : Debug: pap {Tue Feb 15 07:49:22 2022 : Debug: normalise = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_preprocess, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_preprocessTue Feb 15 07:49:22 2022 : Debug: # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocessTue Feb 15 07:49:22 2022 : Debug: preprocess {Tue Feb 15 07:49:22 2022 : Debug: huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups"Tue Feb 15 07:49:22 2022 : Debug: hints = "/etc/freeradius/3.0/mods-config/preprocess/hints"Tue Feb 15 07:49:22 2022 : Debug: with_ascend_hack = noTue Feb 15 07:49:22 2022 : Debug: ascend_channels_per_line = 23Tue Feb 15 07:49:22 2022 : Debug: with_ntdomain_hack = noTue Feb 15 07:49:22 2022 : Debug: with_specialix_jetstream_hack = noTue Feb 15 07:49:22 2022 : Debug: with_cisco_vsa_hack = noTue Feb 15 07:49:22 2022 : Debug: with_alvarion_vsa_hack = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_mschap with path: /usr/lib/freeradius/rlm_mschap.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_mschap, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_mschapTue Feb 15 07:49:22 2022 : Debug: # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschapTue Feb 15 07:49:22 2022 : Debug: mschap {Tue Feb 15 07:49:22 2022 : Debug: use_mppe = yesTue Feb 15 07:49:22 2022 : Debug: require_encryption = noTue Feb 15 07:49:22 2022 : Debug: require_strong = noTue Feb 15 07:49:22 2022 : Debug: with_ntdomain_hack = yesTue Feb 15 07:49:22 2022 : Debug: ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --domain=LYCEEADER --username=%{mschap:User-Name} --challenge=%{%{mschap:Challenge}:-00} --nt-response=%{%{mschap:NT-Response}:-00}"Tue Feb 15 07:49:22 2022 : Debug: passchange {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: allow_retry = yesTue Feb 15 07:49:22 2022 : Debug: winbind_retry_with_normalised_username = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_logintime with path: /usr/lib/freeradius/rlm_logintime.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_logintime, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_logintimeTue Feb 15 07:49:22 2022 : Debug: # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintimeTue Feb 15 07:49:22 2022 : Debug: logintime {Tue Feb 15 07:49:22 2022 : Debug: minimum_timeout = 60Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_soh with path: /usr/lib/freeradius/rlm_soh.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_soh, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_sohTue Feb 15 07:49:22 2022 : Debug: # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/sohTue Feb 15 07:49:22 2022 : Debug: soh {Tue Feb 15 07:49:22 2022 : Debug: dhcp = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_exec, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_execTue Feb 15 07:49:22 2022 : Debug: # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echoTue Feb 15 07:49:22 2022 : Debug: exec echo {Tue Feb 15 07:49:22 2022 : Debug: wait = yesTue Feb 15 07:49:22 2022 : Debug: program = "/bin/echo %{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: input_pairs = "request"Tue Feb 15 07:49:22 2022 : Debug: output_pairs = "reply"Tue Feb 15 07:49:22 2022 : Debug: shell_escape = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_chap, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_chapTue Feb 15 07:49:22 2022 : Debug: # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chapTue Feb 15 07:49:22 2022 : Debug: Loading rlm_attr_filter with path: /usr/lib/freeradius/rlm_attr_filter.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_attr_filter, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_attr_filterTue Feb 15 07:49:22 2022 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: attr_filter attr_filter.post-proxy {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy"Tue Feb 15 07:49:22 2022 : Debug: key = "%{Realm}"Tue Feb 15 07:49:22 2022 : Debug: relaxed = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: attr_filter attr_filter.pre-proxy {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy"Tue Feb 15 07:49:22 2022 : Debug: key = "%{Realm}"Tue Feb 15 07:49:22 2022 : Debug: relaxed = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: attr_filter attr_filter.access_reject {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject"Tue Feb 15 07:49:22 2022 : Debug: key = "%{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: relaxed = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: attr_filter attr_filter.access_challenge {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge"Tue Feb 15 07:49:22 2022 : Debug: key = "%{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: relaxed = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: attr_filter attr_filter.accounting_response {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response"Tue Feb 15 07:49:22 2022 : Debug: key = "%{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: relaxed = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/execTue Feb 15 07:49:22 2022 : Debug: exec {Tue Feb 15 07:49:22 2022 : Debug: wait = noTue Feb 15 07:49:22 2022 : Debug: input_pairs = "request"Tue Feb 15 07:49:22 2022 : Debug: shell_escape = yesTue Feb 15 07:49:22 2022 : Debug: timeout = 10Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_always with path: /usr/lib/freeradius/rlm_always.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_always, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_alwaysTue Feb 15 07:49:22 2022 : Debug: # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always reject {Tue Feb 15 07:49:22 2022 : Debug: rcode = "reject"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always fail {Tue Feb 15 07:49:22 2022 : Debug: rcode = "fail"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always ok {Tue Feb 15 07:49:22 2022 : Debug: rcode = "ok"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always handled {Tue Feb 15 07:49:22 2022 : Debug: rcode = "handled"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always invalid {Tue Feb 15 07:49:22 2022 : Debug: rcode = "invalid"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always userlock {Tue Feb 15 07:49:22 2022 : Debug: rcode = "userlock"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always notfound {Tue Feb 15 07:49:22 2022 : Debug: rcode = "notfound"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always noop {Tue Feb 15 07:49:22 2022 : Debug: rcode = "noop"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: always updated {Tue Feb 15 07:49:22 2022 : Debug: rcode = "updated"Tue Feb 15 07:49:22 2022 : Debug: simulcount = 0Tue Feb 15 07:49:22 2022 : Debug: mpp = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_dynamic_clients with path: /usr/lib/freeradius/rlm_dynamic_clients.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_dynamic_clients, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_dynamic_clientsTue Feb 15 07:49:22 2022 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clientsTue Feb 15 07:49:22 2022 : Debug: Loading rlm_radutmp with path: /usr/lib/freeradius/rlm_radutmp.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_radutmp, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_radutmpTue Feb 15 07:49:22 2022 : Debug: # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmpTue Feb 15 07:49:22 2022 : Debug: radutmp sradutmp {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/sradutmp"Tue Feb 15 07:49:22 2022 : Debug: username = "%{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: case_sensitive = yesTue Feb 15 07:49:22 2022 : Debug: check_with_nas = yesTue Feb 15 07:49:22 2022 : Debug: permissions = 420Tue Feb 15 07:49:22 2022 : Debug: caller_id = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmpTue Feb 15 07:49:22 2022 : Debug: radutmp {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radutmp"Tue Feb 15 07:49:22 2022 : Debug: username = "%{User-Name}"Tue Feb 15 07:49:22 2022 : Debug: case_sensitive = yesTue Feb 15 07:49:22 2022 : Debug: check_with_nas = yesTue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: caller_id = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_unix with path: /usr/lib/freeradius/rlm_unix.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_unix, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_unixTue Feb 15 07:49:22 2022 : Debug: # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unixTue Feb 15 07:49:22 2022 : Debug: unix {Tue Feb 15 07:49:22 2022 : Debug: radwtmp = "/var/log/freeradius/radwtmp"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Creating attribute Unix-GroupTue Feb 15 07:49:22 2022 : Debug: Loading rlm_passwd with path: /usr/lib/freeradius/rlm_passwd.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_passwd, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_passwdTue Feb 15 07:49:22 2022 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwdTue Feb 15 07:49:22 2022 : Debug: passwd etc_passwd {Tue Feb 15 07:49:22 2022 : Debug: filename = "/etc/passwd"Tue Feb 15 07:49:22 2022 : Debug: format = "*User-Name:Crypt-Password:"Tue Feb 15 07:49:22 2022 : Debug: delimiter = ":"Tue Feb 15 07:49:22 2022 : Debug: ignore_nislike = noTue Feb 15 07:49:22 2022 : Debug: ignore_empty = yesTue Feb 15 07:49:22 2022 : Debug: allow_multiple_keys = noTue Feb 15 07:49:22 2022 : Debug: hash_size = 100Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_realm with path: /usr/lib/freeradius/rlm_realm.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_realm, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_realmTue Feb 15 07:49:22 2022 : Debug: # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: realm IPASS {Tue Feb 15 07:49:22 2022 : Debug: format = "prefix"Tue Feb 15 07:49:22 2022 : Debug: delimiter = "/"Tue Feb 15 07:49:22 2022 : Debug: ignore_default = noTue Feb 15 07:49:22 2022 : Debug: ignore_null = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: realm suffix {Tue Feb 15 07:49:22 2022 : Debug: format = "suffix"Tue Feb 15 07:49:22 2022 : Debug: delimiter = "@"Tue Feb 15 07:49:22 2022 : Debug: ignore_default = noTue Feb 15 07:49:22 2022 : Debug: ignore_null = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: realm realmpercent {Tue Feb 15 07:49:22 2022 : Debug: format = "suffix"Tue Feb 15 07:49:22 2022 : Debug: delimiter = "%"Tue Feb 15 07:49:22 2022 : Debug: ignore_default = noTue Feb 15 07:49:22 2022 : Debug: ignore_null = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: realm ntdomain {Tue Feb 15 07:49:22 2022 : Debug: format = "prefix"Tue Feb 15 07:49:22 2022 : Debug: delimiter = "\\"Tue Feb 15 07:49:22 2022 : Debug: ignore_default = noTue Feb 15 07:49:22 2022 : Debug: ignore_null = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_expr, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_exprTue Feb 15 07:49:22 2022 : Debug: # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/exprTue Feb 15 07:49:22 2022 : Debug: expr {Tue Feb 15 07:49:22 2022 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_replicate with path: /usr/lib/freeradius/rlm_replicate.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_replicate, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_replicateTue Feb 15 07:49:22 2022 : Debug: # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicateTue Feb 15 07:49:22 2022 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_authTue Feb 15 07:49:22 2022 : Debug: exec ntlm_auth {Tue Feb 15 07:49:22 2022 : Debug: wait = yesTue Feb 15 07:49:22 2022 : Debug: program = "/usr/bin/ntlm_auth --request-nt-key --domain=LYCEEADER --username=%{mschap:User-Name} --password=%{User-Password}"Tue Feb 15 07:49:22 2022 : Debug: shell_escape = yesTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: detail auth_log {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"Tue Feb 15 07:49:22 2022 : Debug: header = "%t"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: locking = noTue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: log_packet_header = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: detail reply_log {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"Tue Feb 15 07:49:22 2022 : Debug: header = "%t"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: locking = noTue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: log_packet_header = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: detail pre_proxy_log {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"Tue Feb 15 07:49:22 2022 : Debug: header = "%t"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: locking = noTue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: log_packet_header = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: detail post_proxy_log {Tue Feb 15 07:49:22 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"Tue Feb 15 07:49:22 2022 : Debug: header = "%t"Tue Feb 15 07:49:22 2022 : Debug: permissions = 384Tue Feb 15 07:49:22 2022 : Debug: locking = noTue Feb 15 07:49:22 2022 : Debug: escape_filenames = noTue Feb 15 07:49:22 2022 : Debug: log_packet_header = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_utf8 with path: /usr/lib/freeradius/rlm_utf8.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_utf8, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_utf8Tue Feb 15 07:49:22 2022 : Debug: # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_eap with path: /usr/lib/freeradius/rlm_eap.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_eap, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_eapTue Feb 15 07:49:22 2022 : Debug: # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eapTue Feb 15 07:49:22 2022 : Debug: eap {Tue Feb 15 07:49:22 2022 : Debug: default_eap_type = "ttls"Tue Feb 15 07:49:22 2022 : Debug: timer_expire = 60Tue Feb 15 07:49:22 2022 : Debug: ignore_unknown_eap_types = noTue Feb 15 07:49:22 2022 : Debug: cisco_accounting_username_bug = noTue Feb 15 07:49:22 2022 : Debug: max_sessions = 4096Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_cache with path: /usr/lib/freeradius/rlm_cache.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_cache, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_cacheTue Feb 15 07:49:22 2022 : Debug: # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eapTue Feb 15 07:49:22 2022 : Debug: cache cache_eap {Tue Feb 15 07:49:22 2022 : Debug: driver = "rlm_cache_rbtree"Tue Feb 15 07:49:22 2022 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"Tue Feb 15 07:49:22 2022 : Debug: ttl = 15Tue Feb 15 07:49:22 2022 : Debug: max_entries = 0Tue Feb 15 07:49:22 2022 : Debug: epoch = 0Tue Feb 15 07:49:22 2022 : Debug: add_stats = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_ldap with path: /usr/lib/freeradius/rlm_ldap.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_ldap, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_ldapTue Feb 15 07:49:22 2022 : Debug: # Loading module "ldap" from file /etc/freeradius/3.0/mods-enabled/ldapTue Feb 15 07:49:22 2022 : Debug: ldap {Tue Feb 15 07:49:22 2022 : Debug: server = "se4ad.lyceeader.eu"Tue Feb 15 07:49:22 2022 : Debug: identity = "CN=Administrator,CN=Users,DC=lyceeader,DC=eu"Tue Feb 15 07:49:22 2022 : Debug: password = "Audin77Lubin"Tue Feb 15 07:49:22 2022 : Debug: sasl {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: user {Tue Feb 15 07:49:22 2022 : Debug: scope = "sub"Tue Feb 15 07:49:22 2022 : Debug: access_positive = yesTue Feb 15 07:49:22 2022 : Debug: sasl {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: group {Tue Feb 15 07:49:22 2022 : Debug: scope = "sub"Tue Feb 15 07:49:22 2022 : Debug: name_attribute = "cn"Tue Feb 15 07:49:22 2022 : Debug: membership_filter = "(|(member=%{control:Ldap-UserDn})(memberUid=%{%{Stripped-User-Name}:-%{User-Name}}))"Tue Feb 15 07:49:22 2022 : Debug: cacheable_name = noTue Feb 15 07:49:22 2022 : Debug: cacheable_dn = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: client {Tue Feb 15 07:49:22 2022 : Debug: filter = "(objectClass=radiusClient)"Tue Feb 15 07:49:22 2022 : Debug: scope = "sub"Tue Feb 15 07:49:22 2022 : Debug: base_dn = "dc=lyceeader,dc=eu"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: profile {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: options {Tue Feb 15 07:49:22 2022 : Debug: ldap_debug = 40Tue Feb 15 07:49:22 2022 : Debug: chase_referrals = yesTue Feb 15 07:49:22 2022 : Debug: rebind = yesTue Feb 15 07:49:22 2022 : Debug: net_timeout = 1Tue Feb 15 07:49:22 2022 : Debug: res_timeout = 10Tue Feb 15 07:49:22 2022 : Debug: srv_timelimit = 3Tue Feb 15 07:49:22 2022 : Debug: idle = 60Tue Feb 15 07:49:22 2022 : Debug: probes = 3Tue Feb 15 07:49:22 2022 : Debug: interval = 3Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: tls {Tue Feb 15 07:49:22 2022 : Debug: start_tls = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Creating attribute LDAP-GroupTue Feb 15 07:49:22 2022 : Debug: Loading rlm_expiration with path: /usr/lib/freeradius/rlm_expiration.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_expiration, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_expirationTue Feb 15 07:49:22 2022 : Debug: # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expirationTue Feb 15 07:49:22 2022 : Debug: Loading rlm_unpack with path: /usr/lib/freeradius/rlm_unpack.soTue Feb 15 07:49:22 2022 : Debug: Loaded rlm_unpack, checking if it's validTue Feb 15 07:49:22 2022 : Debug: # Loaded module rlm_unpackTue Feb 15 07:49:22 2022 : Debug: # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpackTue Feb 15 07:49:22 2022 : Debug: instantiate {Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detailTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelogTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelogTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/filesTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/authorizeTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/accountingTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxyTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/papTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocessTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroupsTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hintsTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschapTue Feb 15 07:49:22 2022 : Debug: rlm_mschap (mschap): authenticating by calling 'ntlm_auth'Tue Feb 15 07:49:22 2022 : Debug: # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintimeTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxyTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxyTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_rejectTue Feb 15 07:49:22 2022 : Warning: [/etc/freeradius/3.0/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Tue Feb 15 07:49:22 2022 : 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". Tue Feb 15 07:49:22 2022 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challengeTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filterTue Feb 15 07:49:22 2022 : Debug: reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_responseTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/alwaysTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwdTue Feb 15 07:49:22 2022 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: noTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realmTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail outputTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.logTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eapTue Feb 15 07:49:22 2022 : Debug: Loading rlm_eap_tls with path: /usr/lib/freeradius/rlm_eap_tls.soTue Feb 15 07:49:22 2022 : Debug: # Linked to sub-module rlm_eap_tlsTue Feb 15 07:49:22 2022 : Debug: tls {Tue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[10]: The item 'cadir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[11]: The item 'private_key_password' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[12]: The item 'private_key_file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[14]: The item 'certificate_file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[16]: The item 'ca_file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[18]: The item 'dh_file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[19]: The item 'random_file' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[21]: The item 'cipher_list' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[22]: The item 'cipher_server_preference' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[23]: The item 'make_cert_command' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[24]: The item 'ecdh_curve' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Info: TLS section "tls" missing, trying to use legacy configurationTue Feb 15 07:49:22 2022 : Debug: tls {Tue Feb 15 07:49:22 2022 : Debug: verify_depth = 0Tue Feb 15 07:49:22 2022 : Debug: pem_file_type = yesTue Feb 15 07:49:22 2022 : Debug: private_key_file = "/etc/ssl/private/ssl-cert-snakeoil.key"Tue Feb 15 07:49:22 2022 : Debug: certificate_file = "/etc/ssl/certs/ssl-cert-snakeoil.pem"Tue Feb 15 07:49:22 2022 : Debug: ca_file = "/etc/ssl/certs/ca-certificates.crt"Tue Feb 15 07:49:22 2022 : Debug: private_key_password = "aderader"Tue Feb 15 07:49:22 2022 : Debug: dh_file = "/etc/freeradius/3.0/certs/dh"Tue Feb 15 07:49:22 2022 : Debug: random_file = "/dev/urandom"Tue Feb 15 07:49:22 2022 : Debug: fragment_size = 1024Tue Feb 15 07:49:22 2022 : Debug: include_length = yesTue Feb 15 07:49:22 2022 : Debug: auto_chain = yesTue Feb 15 07:49:22 2022 : Debug: check_crl = noTue Feb 15 07:49:22 2022 : Debug: check_all_crl = noTue Feb 15 07:49:22 2022 : Debug: cipher_list = "DEFAULT"Tue Feb 15 07:49:22 2022 : Debug: cipher_server_preference = noTue Feb 15 07:49:22 2022 : Debug: ecdh_curve = "prime256v1"Tue Feb 15 07:49:22 2022 : Debug: tls_max_version = ""Tue Feb 15 07:49:22 2022 : Debug: tls_min_version = "1.0"Tue Feb 15 07:49:22 2022 : Debug: cache {Tue Feb 15 07:49:22 2022 : Debug: enable = noTue Feb 15 07:49:22 2022 : Debug: lifetime = 24Tue Feb 15 07:49:22 2022 : Debug: max_entries = 255Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: verify {Tue Feb 15 07:49:22 2022 : Debug: skip_if_ocsp_ok = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: ocsp {Tue Feb 15 07:49:22 2022 : Debug: enable = noTue Feb 15 07:49:22 2022 : Debug: override_cert_url = noTue Feb 15 07:49:22 2022 : Debug: use_nonce = yesTue Feb 15 07:49:22 2022 : Debug: timeout = 0Tue Feb 15 07:49:22 2022 : Debug: softfail = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[10]: The item 'cadir' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Warning: /etc/freeradius/3.0/mods-enabled/eap[23]: The item 'make_cert_command' is defined, but is unused by the configurationTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: Loading rlm_eap_ttls with path: /usr/lib/freeradius/rlm_eap_ttls.soTue Feb 15 07:49:22 2022 : Debug: # Linked to sub-module rlm_eap_ttlsTue Feb 15 07:49:22 2022 : Debug: ttls {Tue Feb 15 07:49:22 2022 : Debug: default_eap_type = "mschapv2"Tue Feb 15 07:49:22 2022 : Debug: copy_request_to_tunnel = yesTue Feb 15 07:49:22 2022 : Debug: use_tunneled_reply = yesTue Feb 15 07:49:22 2022 : Debug: virtual_server = "inner-tunnel"Tue Feb 15 07:49:22 2022 : Debug: include_length = yesTue Feb 15 07:49:22 2022 : Debug: require_client_cert = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Info: TLS section "tls" missing, trying to use legacy configurationTue Feb 15 07:49:22 2022 : Debug: tls: Using cached TLS configuration from previous invocationTue Feb 15 07:49:22 2022 : Debug: Loading rlm_eap_peap with path: /usr/lib/freeradius/rlm_eap_peap.soTue Feb 15 07:49:22 2022 : Debug: # Linked to sub-module rlm_eap_peapTue Feb 15 07:49:22 2022 : Debug: peap {Tue Feb 15 07:49:22 2022 : Debug: default_eap_type = "mschapv2"Tue Feb 15 07:49:22 2022 : Debug: copy_request_to_tunnel = yesTue Feb 15 07:49:22 2022 : Debug: use_tunneled_reply = yesTue Feb 15 07:49:22 2022 : Debug: proxy_tunneled_request_as_eap = yesTue Feb 15 07:49:22 2022 : Debug: virtual_server = "inner-tunnel"Tue Feb 15 07:49:22 2022 : Debug: soh = noTue Feb 15 07:49:22 2022 : Debug: require_client_cert = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Info: TLS section "tls" missing, trying to use legacy configurationTue Feb 15 07:49:22 2022 : Debug: tls: Using cached TLS configuration from previous invocationTue Feb 15 07:49:22 2022 : Debug: Loading rlm_eap_mschapv2 with path: /usr/lib/freeradius/rlm_eap_mschapv2.soTue Feb 15 07:49:22 2022 : Debug: # Linked to sub-module rlm_eap_mschapv2Tue Feb 15 07:49:22 2022 : Debug: mschapv2 {Tue Feb 15 07:49:22 2022 : Debug: with_ntdomain_hack = noTue Feb 15 07:49:22 2022 : Debug: send_error = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eapTue Feb 15 07:49:22 2022 : Debug: Loading rlm_cache_rbtree with path: /usr/lib/freeradius/rlm_cache_rbtree.soTue Feb 15 07:49:22 2022 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linkedTue Feb 15 07:49:22 2022 : Debug: # Instantiating module "ldap" from file /etc/freeradius/3.0/mods-enabled/ldapTue Feb 15 07:49:22 2022 : Info: rlm_ldap: libldap vendor: OpenLDAP, version: 20447Tue Feb 15 07:49:22 2022 : Debug: accounting {Tue Feb 15 07:49:22 2022 : Debug: reference = "%{tolower:type.%{Acct-Status-Type}}"Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: post-auth {Tue Feb 15 07:49:22 2022 : Debug: reference = "."Tue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Debug: LDAP server string: ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Using local pool sectionTue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): No pool reference found for config item "ldap.pool"Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Initialising connection poolTue Feb 15 07:49:22 2022 : Debug: pool {Tue Feb 15 07:49:22 2022 : Debug: start = 5Tue Feb 15 07:49:22 2022 : Debug: min = 3Tue Feb 15 07:49:22 2022 : Debug: max = 32Tue Feb 15 07:49:22 2022 : Debug: spare = 10Tue Feb 15 07:49:22 2022 : Debug: uses = 0Tue Feb 15 07:49:22 2022 : Debug: lifetime = 0Tue Feb 15 07:49:22 2022 : Debug: cleanup_interval = 30Tue Feb 15 07:49:22 2022 : Debug: idle_timeout = 60Tue Feb 15 07:49:22 2022 : Debug: retry_delay = 30Tue Feb 15 07:49:22 2022 : Debug: spread = noTue Feb 15 07:49:22 2022 : Debug: }Tue Feb 15 07:49:22 2022 : Info: rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots usedTue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Connecting to ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): New libldap handle 0x55bdfc36be80Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Waiting for bind result...Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Bind successfulTue Feb 15 07:49:22 2022 : Info: rlm_ldap (ldap): Opening additional connection (1), 1 of 31 pending slots usedTue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Connecting to ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): New libldap handle 0x55bdfc36dfe0Tue Feb 15 07:49:22 2022 : Debug: rlm_ldap (ldap): Waiting for bind result...Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Bind successfulTue Feb 15 07:49:23 2022 : Info: rlm_ldap (ldap): Opening additional connection (2), 1 of 30 pending slots usedTue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Connecting to ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): New libldap handle 0x55bdfc38d6b0Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Waiting for bind result...Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Bind successfulTue Feb 15 07:49:23 2022 : Info: rlm_ldap (ldap): Opening additional connection (3), 1 of 29 pending slots usedTue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Connecting to ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): New libldap handle 0x55bdfc38e170Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Waiting for bind result...Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Bind successfulTue Feb 15 07:49:23 2022 : Info: rlm_ldap (ldap): Opening additional connection (4), 1 of 28 pending slots usedTue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Connecting to ldap://se4ad.lyceeader.eu:389Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): New libldap handle 0x55bdfc3a4460Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Waiting for bind result...Tue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Bind successfulTue Feb 15 07:49:23 2022 : Debug: rlm_ldap (ldap): Adding pool reference 0x55bdfc341100 to config item "ldap.pool"Tue Feb 15 07:49:23 2022 : Debug: # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expirationTue Feb 15 07:49:23 2022 : Debug: } # modulesTue Feb 15 07:49:23 2022 : Debug: radiusd: #### Loading Virtual Servers ####Tue Feb 15 07:49:23 2022 : Debug: server { # from file /etc/freeradius/3.0/radiusd.confTue Feb 15 07:49:23 2022 : Debug: } # serverTue Feb 15 07:49:23 2022 : Debug: server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnelTue Feb 15 07:49:23 2022 : Debug: authenticate {Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: papTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: chapTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: } # authenticateTue Feb 15 07:49:23 2022 : Debug: authorize {Tue Feb 15 07:49:23 2022 : Debug: policy filter_username {Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name) {Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ / /) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@[^@]*@/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /\.\./) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@\./) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: chapTue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: suffixTue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &control:Proxy-To-Realm := LOCALTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: filesTue Feb 15 07:49:23 2022 : Warning: Ignoring "sql" (see raddb/mods-available/README.rst)Tue Feb 15 07:49:23 2022 : Debug: ldapTue Feb 15 07:49:23 2022 : Debug: expirationTue Feb 15 07:49:23 2022 : Debug: logintimeTue Feb 15 07:49:23 2022 : Debug: papTue Feb 15 07:49:23 2022 : Debug: } # authorizeTue Feb 15 07:49:23 2022 : Debug: session {Tue Feb 15 07:49:23 2022 : Debug: radutmpTue Feb 15 07:49:23 2022 : Debug: } # sessionTue Feb 15 07:49:23 2022 : Debug: post-proxy {Tue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: } # post-proxyTue Feb 15 07:49:23 2022 : Debug: post-auth {Tue Feb 15 07:49:23 2022 : Info: # Skipping contents of 'if' as it is always 'false' -- /etc/freeradius/3.0/sites-enabled/inner-tunnel:331Tue Feb 15 07:49:23 2022 : Debug: if (false) {Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: attr_filter.access_rejectTue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-MessageTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: } # post-authTue Feb 15 07:49:23 2022 : Debug: } # server inner-tunnelTue Feb 15 07:49:23 2022 : Debug: server default { # from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:23 2022 : Debug: authenticate {Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: papTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: chapTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: digestTue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: } # authenticateTue Feb 15 07:49:23 2022 : Debug: authorize {Tue Feb 15 07:49:23 2022 : Debug: policy filter_username {Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name) {Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ / /) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@[^@]*@/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /\.\./) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if (&User-Name =~ /@\./) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot'Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: rejectTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: preprocessTue Feb 15 07:49:23 2022 : Debug: chapTue Feb 15 07:49:23 2022 : Debug: mschapTue Feb 15 07:49:23 2022 : Debug: digestTue Feb 15 07:49:23 2022 : Debug: suffixTue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: filesTue Feb 15 07:49:23 2022 : Debug: ldapTue Feb 15 07:49:23 2022 : Debug: expirationTue Feb 15 07:49:23 2022 : Debug: logintimeTue Feb 15 07:49:23 2022 : Debug: papTue Feb 15 07:49:23 2022 : Debug: } # authorizeTue Feb 15 07:49:23 2022 : Debug: preacct {Tue Feb 15 07:49:23 2022 : Debug: preprocessTue Feb 15 07:49:23 2022 : Debug: policy acct_unique {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Tmp-String-9 := "ai:"Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}"Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: else {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}"Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: suffixTue Feb 15 07:49:23 2022 : Debug: filesTue Feb 15 07:49:23 2022 : Debug: } # preacctTue Feb 15 07:49:23 2022 : Debug: accounting {Tue Feb 15 07:49:23 2022 : Debug: detailTue Feb 15 07:49:23 2022 : Debug: unixTue Feb 15 07:49:23 2022 : Debug: execTue Feb 15 07:49:23 2022 : Debug: attr_filter.accounting_responseTue Feb 15 07:49:23 2022 : Debug: } # accountingTue Feb 15 07:49:23 2022 : Debug: post-proxy {Tue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: } # post-proxyTue Feb 15 07:49:23 2022 : Debug: post-auth {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &reply:[*] += &session-state:[*]Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: execTue Feb 15 07:49:23 2022 : Debug: policy remove_reply_message_if_eap {Tue Feb 15 07:49:23 2022 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &reply:Reply-Message !* ANYTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: else {Tue Feb 15 07:49:23 2022 : Debug: noopTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: attr_filter.access_rejectTue Feb 15 07:49:23 2022 : Debug: eapTue Feb 15 07:49:23 2022 : Debug: policy remove_reply_message_if_eap {Tue Feb 15 07:49:23 2022 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) {Tue Feb 15 07:49:23 2022 : Debug: update {Tue Feb 15 07:49:23 2022 : Debug: &reply:Reply-Message !* ANYTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: else {Tue Feb 15 07:49:23 2022 : Debug: noopTue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: group {Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: } # post-authTue Feb 15 07:49:23 2022 : Debug: } # server defaultTue Feb 15 07:49:23 2022 : Debug: Created signal pipe. Read end FD 11, write end FD 12Tue Feb 15 07:49:23 2022 : Debug: radiusd: #### Opening IP addresses and Ports ####Tue Feb 15 07:49:23 2022 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.soTue Feb 15 07:49:23 2022 : 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 directoryTue Feb 15 07:49:23 2022 : Debug: Loading library using linker search path(s)Tue Feb 15 07:49:23 2022 : Debug: Defaults : /lib:/usr/libTue Feb 15 07:49:23 2022 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directoryTue Feb 15 07:49:23 2022 : Debug: listen {Tue Feb 15 07:49:23 2022 : Debug: type = "auth"Tue Feb 15 07:49:23 2022 : Debug: ipaddr = 127.0.0.1Tue Feb 15 07:49:23 2022 : Debug: port = 18120Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.soTue Feb 15 07:49:23 2022 : 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 directoryTue Feb 15 07:49:23 2022 : Debug: Loading library using linker search path(s)Tue Feb 15 07:49:23 2022 : Debug: Defaults : /lib:/usr/libTue Feb 15 07:49:23 2022 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directoryTue Feb 15 07:49:23 2022 : Debug: listen {Tue Feb 15 07:49:23 2022 : Debug: type = "auth"Tue Feb 15 07:49:23 2022 : Debug: ipaddr = *Tue Feb 15 07:49:23 2022 : Debug: port = 1812Tue Feb 15 07:49:23 2022 : Debug: limit {Tue Feb 15 07:49:23 2022 : Debug: max_connections = 16Tue Feb 15 07:49:23 2022 : Debug: lifetime = 0Tue Feb 15 07:49:23 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.soTue Feb 15 07:49:23 2022 : 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 directoryTue Feb 15 07:49:23 2022 : Debug: Loading library using linker search path(s)Tue Feb 15 07:49:23 2022 : Debug: Defaults : /lib:/usr/libTue Feb 15 07:49:23 2022 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directoryTue Feb 15 07:49:23 2022 : Debug: listen {Tue Feb 15 07:49:23 2022 : Debug: type = "acct"Tue Feb 15 07:49:23 2022 : Debug: ipaddr = *Tue Feb 15 07:49:23 2022 : Debug: port = 0Tue Feb 15 07:49:23 2022 : Debug: limit {Tue Feb 15 07:49:23 2022 : Debug: max_connections = 16Tue Feb 15 07:49:23 2022 : Debug: lifetime = 0Tue Feb 15 07:49:23 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.soTue Feb 15 07:49:23 2022 : 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 directoryTue Feb 15 07:49:23 2022 : Debug: Loading library using linker search path(s)Tue Feb 15 07:49:23 2022 : Debug: Defaults : /lib:/usr/libTue Feb 15 07:49:23 2022 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directoryTue Feb 15 07:49:23 2022 : Debug: listen {Tue Feb 15 07:49:23 2022 : Debug: type = "auth"Tue Feb 15 07:49:23 2022 : Debug: ipv6addr = ::Tue Feb 15 07:49:23 2022 : Debug: port = 0Tue Feb 15 07:49:23 2022 : Debug: limit {Tue Feb 15 07:49:23 2022 : Debug: max_connections = 16Tue Feb 15 07:49:23 2022 : Debug: lifetime = 0Tue Feb 15 07:49:23 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.soTue Feb 15 07:49:23 2022 : 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 directoryTue Feb 15 07:49:23 2022 : Debug: Loading library using linker search path(s)Tue Feb 15 07:49:23 2022 : Debug: Defaults : /lib:/usr/libTue Feb 15 07:49:23 2022 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directoryTue Feb 15 07:49:23 2022 : Debug: listen {Tue Feb 15 07:49:23 2022 : Debug: type = "acct"Tue Feb 15 07:49:23 2022 : Debug: ipv6addr = ::Tue Feb 15 07:49:23 2022 : Debug: port = 0Tue Feb 15 07:49:23 2022 : Debug: limit {Tue Feb 15 07:49:23 2022 : Debug: max_connections = 16Tue Feb 15 07:49:23 2022 : Debug: lifetime = 0Tue Feb 15 07:49:23 2022 : Debug: idle_timeout = 30Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: }Tue Feb 15 07:49:23 2022 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnelTue Feb 15 07:49:23 2022 : Debug: Listening on auth address * port 1812 bound to server defaultTue Feb 15 07:49:23 2022 : Debug: Listening on acct address * port 1813 bound to server defaultTue Feb 15 07:49:23 2022 : Debug: Listening on auth address :: port 1812 bound to server defaultTue Feb 15 07:49:23 2022 : Debug: Listening on acct address :: port 1813 bound to server defaultTue Feb 15 07:49:23 2022 : Debug: Opened new proxy socket 'proxy address * port 58636'Tue Feb 15 07:49:23 2022 : Debug: Listening on proxy address * port 58636Tue Feb 15 07:49:23 2022 : Debug: Opened new proxy socket 'proxy address :: port 56746'Tue Feb 15 07:49:23 2022 : Debug: Listening on proxy address :: port 56746Tue Feb 15 07:49:23 2022 : Info: Ready to process requestsTue Feb 15 07:49:23 2022 : Debug: (0) Received Access-Request Id 154 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:23 2022 : Debug: (0) User-Name = "eric.roger"Tue Feb 15 07:49:23 2022 : Debug: (0) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:23 2022 : Debug: (0) NAS-Port = 0Tue Feb 15 07:49:23 2022 : Debug: (0) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:23 2022 : Debug: (0) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:23 2022 : Debug: (0) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:23 2022 : Debug: (0) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:23 2022 : Debug: (0) Service-Type = Framed-UserTue Feb 15 07:49:23 2022 : Debug: (0) Framed-MTU = 1100Tue Feb 15 07:49:23 2022 : Debug: (0) EAP-Message = 0x0208000f01657269632e726f676572Tue Feb 15 07:49:23 2022 : Debug: (0) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:23 2022 : Debug: (0) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:23 2022 : Debug: (0) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:23 2022 : Debug: (0) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:23 2022 : Debug: (0) Message-Authenticator = 0x7146bcf2b773fddacdd486633aa156a5Tue Feb 15 07:49:23 2022 : Debug: (0) session-state: No State attributeTue Feb 15 07:49:23 2022 : Debug: (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:23 2022 : Debug: (0) authorize {Tue Feb 15 07:49:23 2022 : Debug: (0) policy filter_username {Tue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name) {Tue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name) -> TRUETue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name) {Tue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ / /) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:23 2022 : Debug: No matchesTue Feb 15 07:49:23 2022 : Debug: (0) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:23 2022 : Debug: (0) } # if (&User-Name) = notfoundTue Feb 15 07:49:23 2022 : Debug: (0) } # policy filter_username = notfoundTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:23 2022 : Debug: (0) [preprocess] = okTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:23 2022 : Debug: (0) [chap] = noopTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:23 2022 : Debug: (0) [mschap] = noopTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:23 2022 : Debug: (0) [digest] = noopTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:23 2022 : Debug: (0) suffix: Checking for suffix after "@"Tue Feb 15 07:49:23 2022 : Debug: (0) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:23 2022 : Debug: (0) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:23 2022 : Debug: (0) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:23 2022 : Debug: (0) suffix: Authentication realm is LOCALTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:23 2022 : Debug: (0) [suffix] = okTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:23 2022 : Debug: (0) eap: Peer sent EAP Response (code 2) ID 8 length 15Tue Feb 15 07:49:23 2022 : Debug: (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:23 2022 : Debug: (0) [eap] = okTue Feb 15 07:49:23 2022 : Debug: (0) } # authorize = okTue Feb 15 07:49:23 2022 : Debug: (0) Found Auth-Type = eapTue Feb 15 07:49:23 2022 : Debug: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:23 2022 : Debug: (0) authenticate {Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:23 2022 : Debug: (0) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:23 2022 : Debug: (0) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:23 2022 : Debug: (0) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:23 2022 : Debug: (0) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:23 2022 : Debug: (0) eap: Sending EAP Request (code 1) ID 9 length 6Tue Feb 15 07:49:23 2022 : Debug: (0) eap: EAP session adding &reply:State = 0xfcef27c1fce632b5Tue Feb 15 07:49:23 2022 : Debug: (0) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:23 2022 : Debug: (0) [eap] = handledTue Feb 15 07:49:23 2022 : Debug: (0) } # authenticate = handledTue Feb 15 07:49:23 2022 : Debug: (0) Using Post-Auth-Type ChallengeTue Feb 15 07:49:23 2022 : Debug: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:23 2022 : Debug: (0) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:23 2022 : Debug: (0) session-state: Nothing to cacheTue Feb 15 07:49:23 2022 : Debug: (0) Sent Access-Challenge Id 154 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:23 2022 : Debug: (0) EAP-Message = 0x010900061520Tue Feb 15 07:49:23 2022 : Debug: (0) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:23 2022 : Debug: (0) State = 0xfcef27c1fce632b56e8e47d2a6e92848Tue Feb 15 07:49:23 2022 : Debug: (0) Finished requestTue Feb 15 07:49:23 2022 : Debug: Waking up in 4.9 seconds.Tue Feb 15 07:49:24 2022 : Debug: (1) Received Access-Request Id 158 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:24 2022 : Debug: (1) User-Name = "eric.roger"Tue Feb 15 07:49:24 2022 : Debug: (1) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:24 2022 : Debug: (1) NAS-Port = 0Tue Feb 15 07:49:24 2022 : Debug: (1) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:24 2022 : Debug: (1) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:24 2022 : Debug: (1) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:24 2022 : Debug: (1) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:24 2022 : Debug: (1) Service-Type = Framed-UserTue Feb 15 07:49:24 2022 : Debug: (1) Framed-MTU = 1100Tue Feb 15 07:49:24 2022 : Debug: (1) EAP-Message = 0x020d000f01657269632e726f676572Tue Feb 15 07:49:24 2022 : Debug: (1) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:24 2022 : Debug: (1) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:24 2022 : Debug: (1) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:24 2022 : Debug: (1) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:24 2022 : Debug: (1) Message-Authenticator = 0x2fef1a29c3f874014769537c9e9fea44Tue Feb 15 07:49:24 2022 : Debug: (1) session-state: No State attributeTue Feb 15 07:49:24 2022 : Debug: (1) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:24 2022 : Debug: (1) authorize {Tue Feb 15 07:49:24 2022 : Debug: (1) policy filter_username {Tue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name) {Tue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name) -> TRUETue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name) {Tue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ / /) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:24 2022 : Debug: No matchesTue Feb 15 07:49:24 2022 : Debug: (1) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:24 2022 : Debug: (1) } # if (&User-Name) = notfoundTue Feb 15 07:49:24 2022 : Debug: (1) } # policy filter_username = notfoundTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:24 2022 : Debug: (1) [preprocess] = okTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:24 2022 : Debug: (1) [chap] = noopTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:24 2022 : Debug: (1) [mschap] = noopTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:24 2022 : Debug: (1) [digest] = noopTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:24 2022 : Debug: (1) suffix: Checking for suffix after "@"Tue Feb 15 07:49:24 2022 : Debug: (1) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:24 2022 : Debug: (1) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:24 2022 : Debug: (1) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:24 2022 : Debug: (1) suffix: Authentication realm is LOCALTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:24 2022 : Debug: (1) [suffix] = okTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:24 2022 : Debug: (1) eap: Peer sent EAP Response (code 2) ID 13 length 15Tue Feb 15 07:49:24 2022 : Debug: (1) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:24 2022 : Debug: (1) [eap] = okTue Feb 15 07:49:24 2022 : Debug: (1) } # authorize = okTue Feb 15 07:49:24 2022 : Debug: (1) Found Auth-Type = eapTue Feb 15 07:49:24 2022 : Debug: (1) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:24 2022 : Debug: (1) authenticate {Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:24 2022 : Debug: (1) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:24 2022 : Debug: (1) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:24 2022 : Debug: (1) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:24 2022 : Debug: (1) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:24 2022 : Debug: (1) eap: Sending EAP Request (code 1) ID 14 length 6Tue Feb 15 07:49:24 2022 : Debug: (1) eap: EAP session adding &reply:State = 0x52ee03dd52e01680Tue Feb 15 07:49:24 2022 : Debug: (1) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:24 2022 : Debug: (1) [eap] = handledTue Feb 15 07:49:24 2022 : Debug: (1) } # authenticate = handledTue Feb 15 07:49:24 2022 : Debug: (1) Using Post-Auth-Type ChallengeTue Feb 15 07:49:24 2022 : Debug: (1) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:24 2022 : Debug: (1) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:24 2022 : Debug: (1) session-state: Nothing to cacheTue Feb 15 07:49:24 2022 : Debug: (1) Sent Access-Challenge Id 158 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:24 2022 : Debug: (1) EAP-Message = 0x010e00061520Tue Feb 15 07:49:24 2022 : Debug: (1) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:24 2022 : Debug: (1) State = 0x52ee03dd52e01680d87ed248a86f02b4Tue Feb 15 07:49:24 2022 : Debug: (1) Finished requestTue Feb 15 07:49:24 2022 : Debug: Waking up in 4.8 seconds.Tue Feb 15 07:49:27 2022 : Debug: (2) Received Access-Request Id 157 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:27 2022 : Debug: (2) User-Name = "eric.roger"Tue Feb 15 07:49:27 2022 : Debug: (2) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:27 2022 : Debug: (2) NAS-Port = 0Tue Feb 15 07:49:27 2022 : Debug: (2) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:27 2022 : Debug: (2) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:27 2022 : Debug: (2) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:27 2022 : Debug: (2) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:27 2022 : Debug: (2) Service-Type = Framed-UserTue Feb 15 07:49:27 2022 : Debug: (2) Framed-MTU = 1100Tue Feb 15 07:49:27 2022 : Debug: (2) EAP-Message = 0x020c000f01657269632e726f676572Tue Feb 15 07:49:27 2022 : Debug: (2) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:27 2022 : Debug: (2) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:27 2022 : Debug: (2) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:27 2022 : Debug: (2) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:27 2022 : Debug: (2) Message-Authenticator = 0x9e79ed9502284c1ed826d2459167c085Tue Feb 15 07:49:27 2022 : Debug: (2) session-state: No State attributeTue Feb 15 07:49:27 2022 : Debug: (2) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:27 2022 : Debug: (2) authorize {Tue Feb 15 07:49:27 2022 : Debug: (2) policy filter_username {Tue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name) {Tue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name) -> TRUETue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name) {Tue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ / /) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:27 2022 : Debug: No matchesTue Feb 15 07:49:27 2022 : Debug: (2) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:27 2022 : Debug: (2) } # if (&User-Name) = notfoundTue Feb 15 07:49:27 2022 : Debug: (2) } # policy filter_username = notfoundTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:27 2022 : Debug: (2) [preprocess] = okTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:27 2022 : Debug: (2) [chap] = noopTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:27 2022 : Debug: (2) [mschap] = noopTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:27 2022 : Debug: (2) [digest] = noopTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:27 2022 : Debug: (2) suffix: Checking for suffix after "@"Tue Feb 15 07:49:27 2022 : Debug: (2) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:27 2022 : Debug: (2) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:27 2022 : Debug: (2) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:27 2022 : Debug: (2) suffix: Authentication realm is LOCALTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:27 2022 : Debug: (2) [suffix] = okTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:27 2022 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 12 length 15Tue Feb 15 07:49:27 2022 : Debug: (2) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:27 2022 : Debug: (2) [eap] = okTue Feb 15 07:49:27 2022 : Debug: (2) } # authorize = okTue Feb 15 07:49:27 2022 : Debug: (2) Found Auth-Type = eapTue Feb 15 07:49:27 2022 : Debug: (2) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:27 2022 : Debug: (2) authenticate {Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:27 2022 : Debug: (2) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:27 2022 : Debug: (2) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:27 2022 : Debug: (2) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:27 2022 : Debug: (2) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:27 2022 : Debug: (2) eap: Sending EAP Request (code 1) ID 13 length 6Tue Feb 15 07:49:27 2022 : Debug: (2) eap: EAP session adding &reply:State = 0x9348f1aa9345e4b6Tue Feb 15 07:49:27 2022 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:27 2022 : Debug: (2) [eap] = handledTue Feb 15 07:49:27 2022 : Debug: (2) } # authenticate = handledTue Feb 15 07:49:27 2022 : Debug: (2) Using Post-Auth-Type ChallengeTue Feb 15 07:49:27 2022 : Debug: (2) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:27 2022 : Debug: (2) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:27 2022 : Debug: (2) session-state: Nothing to cacheTue Feb 15 07:49:27 2022 : Debug: (2) Sent Access-Challenge Id 157 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:27 2022 : Debug: (2) EAP-Message = 0x010d00061520Tue Feb 15 07:49:27 2022 : Debug: (2) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:27 2022 : Debug: (2) State = 0x9348f1aa9345e4b6ec1f3ac78b5c7230Tue Feb 15 07:49:27 2022 : Debug: (2) Finished requestTue Feb 15 07:49:27 2022 : Debug: Waking up in 1.2 seconds.Tue Feb 15 07:49:28 2022 : Debug: (3) Received Access-Request Id 155 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:28 2022 : Debug: (3) User-Name = "eric.roger"Tue Feb 15 07:49:28 2022 : Debug: (3) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:28 2022 : Debug: (3) NAS-Port = 0Tue Feb 15 07:49:28 2022 : Debug: (3) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:28 2022 : Debug: (3) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:28 2022 : Debug: (3) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:28 2022 : Debug: (3) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:28 2022 : Debug: (3) Service-Type = Framed-UserTue Feb 15 07:49:28 2022 : Debug: (3) Framed-MTU = 1100Tue Feb 15 07:49:28 2022 : Debug: (3) EAP-Message = 0x0209000f01657269632e726f676572Tue Feb 15 07:49:28 2022 : Debug: (3) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:28 2022 : Debug: (3) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:28 2022 : Debug: (3) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:28 2022 : Debug: (3) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:28 2022 : Debug: (3) Message-Authenticator = 0x21b5cc5db81e229d2dac03a61f8c488cTue Feb 15 07:49:28 2022 : Debug: (3) session-state: No State attributeTue Feb 15 07:49:28 2022 : Debug: (3) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (3) authorize {Tue Feb 15 07:49:28 2022 : Debug: (3) policy filter_username {Tue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name) {Tue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name) -> TRUETue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name) {Tue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ / /) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (3) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:28 2022 : Debug: (3) } # if (&User-Name) = notfoundTue Feb 15 07:49:28 2022 : Debug: (3) } # policy filter_username = notfoundTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:28 2022 : Debug: (3) [preprocess] = okTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:28 2022 : Debug: (3) [chap] = noopTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:28 2022 : Debug: (3) [mschap] = noopTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:28 2022 : Debug: (3) [digest] = noopTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:28 2022 : Debug: (3) suffix: Checking for suffix after "@"Tue Feb 15 07:49:28 2022 : Debug: (3) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:28 2022 : Debug: (3) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:28 2022 : Debug: (3) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:28 2022 : Debug: (3) suffix: Authentication realm is LOCALTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:28 2022 : Debug: (3) [suffix] = okTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (3) eap: Peer sent EAP Response (code 2) ID 9 length 15Tue Feb 15 07:49:28 2022 : Debug: (3) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (3) [eap] = okTue Feb 15 07:49:28 2022 : Debug: (3) } # authorize = okTue Feb 15 07:49:28 2022 : Debug: (3) Found Auth-Type = eapTue Feb 15 07:49:28 2022 : Debug: (3) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (3) authenticate {Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (3) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:28 2022 : Debug: (3) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:28 2022 : Debug: (3) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:28 2022 : Debug: (3) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:28 2022 : Debug: (3) eap: Sending EAP Request (code 1) ID 10 length 6Tue Feb 15 07:49:28 2022 : Debug: (3) eap: EAP session adding &reply:State = 0xb4ed6552b4e77011Tue Feb 15 07:49:28 2022 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (3) [eap] = handledTue Feb 15 07:49:28 2022 : Debug: (3) } # authenticate = handledTue Feb 15 07:49:28 2022 : Debug: (3) Using Post-Auth-Type ChallengeTue Feb 15 07:49:28 2022 : Debug: (3) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (3) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:28 2022 : Debug: (3) session-state: Nothing to cacheTue Feb 15 07:49:28 2022 : Debug: (3) Sent Access-Challenge Id 155 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:28 2022 : Debug: (3) EAP-Message = 0x010a00061520Tue Feb 15 07:49:28 2022 : Debug: (3) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:28 2022 : Debug: (3) State = 0xb4ed6552b4e770115cf193464c90e32cTue Feb 15 07:49:28 2022 : Debug: (3) Finished requestTue Feb 15 07:49:28 2022 : Debug: Waking up in 0.8 seconds.Tue Feb 15 07:49:28 2022 : Debug: (4) Received Access-Request Id 156 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:28 2022 : Debug: (4) User-Name = "eric.roger"Tue Feb 15 07:49:28 2022 : Debug: (4) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:28 2022 : Debug: (4) NAS-Port = 0Tue Feb 15 07:49:28 2022 : Debug: (4) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:28 2022 : Debug: (4) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:28 2022 : Debug: (4) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:28 2022 : Debug: (4) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:28 2022 : Debug: (4) Service-Type = Framed-UserTue Feb 15 07:49:28 2022 : Debug: (4) Framed-MTU = 1100Tue Feb 15 07:49:28 2022 : Debug: (4) EAP-Message = 0x020a000f01657269632e726f676572Tue Feb 15 07:49:28 2022 : Debug: (4) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:28 2022 : Debug: (4) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:28 2022 : Debug: (4) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:28 2022 : Debug: (4) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:28 2022 : Debug: (4) Message-Authenticator = 0x11789da0fc3dffd0c5bb2d6dfeb0fffcTue Feb 15 07:49:28 2022 : Debug: (4) session-state: No State attributeTue Feb 15 07:49:28 2022 : Debug: (4) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (4) authorize {Tue Feb 15 07:49:28 2022 : Debug: (4) policy filter_username {Tue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name) {Tue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name) -> TRUETue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name) {Tue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ / /) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:28 2022 : Debug: No matchesTue Feb 15 07:49:28 2022 : Debug: (4) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:28 2022 : Debug: (4) } # if (&User-Name) = notfoundTue Feb 15 07:49:28 2022 : Debug: (4) } # policy filter_username = notfoundTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:28 2022 : Debug: (4) [preprocess] = okTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:28 2022 : Debug: (4) [chap] = noopTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:28 2022 : Debug: (4) [mschap] = noopTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:28 2022 : Debug: (4) [digest] = noopTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:28 2022 : Debug: (4) suffix: Checking for suffix after "@"Tue Feb 15 07:49:28 2022 : Debug: (4) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:28 2022 : Debug: (4) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:28 2022 : Debug: (4) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:28 2022 : Debug: (4) suffix: Authentication realm is LOCALTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:28 2022 : Debug: (4) [suffix] = okTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (4) eap: Peer sent EAP Response (code 2) ID 10 length 15Tue Feb 15 07:49:28 2022 : Debug: (4) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (4) [eap] = okTue Feb 15 07:49:28 2022 : Debug: (4) } # authorize = okTue Feb 15 07:49:28 2022 : Debug: (4) Found Auth-Type = eapTue Feb 15 07:49:28 2022 : Debug: (4) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (4) authenticate {Tue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (4) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:28 2022 : Debug: (4) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:28 2022 : Debug: (4) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:28 2022 : Debug: (4) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:28 2022 : Debug: (4) eap: Sending EAP Request (code 1) ID 11 length 6Tue Feb 15 07:49:28 2022 : Debug: (4) eap: EAP session adding &reply:State = 0xf169db02f162ceccTue Feb 15 07:49:28 2022 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:28 2022 : Debug: (4) [eap] = handledTue Feb 15 07:49:28 2022 : Debug: (4) } # authenticate = handledTue Feb 15 07:49:28 2022 : Debug: (4) Using Post-Auth-Type ChallengeTue Feb 15 07:49:28 2022 : Debug: (4) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:28 2022 : Debug: (4) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:28 2022 : Debug: (4) session-state: Nothing to cacheTue Feb 15 07:49:28 2022 : Debug: (4) Sent Access-Challenge Id 156 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:28 2022 : Debug: (4) EAP-Message = 0x010b00061520Tue Feb 15 07:49:28 2022 : Debug: (4) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:28 2022 : Debug: (4) State = 0xf169db02f162ceccb887fa5a4defe449Tue Feb 15 07:49:28 2022 : Debug: (4) Finished requestTue Feb 15 07:49:28 2022 : Debug: Waking up in 0.7 seconds.Tue Feb 15 07:49:28 2022 : Debug: (0) Cleaning up request packet ID 154 with timestamp +0Tue Feb 15 07:49:28 2022 : Debug: Waking up in 0.1 seconds.Tue Feb 15 07:49:29 2022 : Debug: (5) Received Access-Request Id 159 from 172.16.251.14:58115 to 172.16.1.232:1812 length 212Tue Feb 15 07:49:29 2022 : Debug: (5) User-Name = "eric.roger"Tue Feb 15 07:49:29 2022 : Debug: (5) NAS-IP-Address = 172.16.251.14Tue Feb 15 07:49:29 2022 : Debug: (5) NAS-Port = 0Tue Feb 15 07:49:29 2022 : Debug: (5) NAS-Identifier = "172.16.251.14"Tue Feb 15 07:49:29 2022 : Debug: (5) NAS-Port-Type = Wireless-802.11Tue Feb 15 07:49:29 2022 : Debug: (5) Calling-Station-Id = "001a138fd604"Tue Feb 15 07:49:29 2022 : Debug: (5) Called-Station-Id = "e82689c6cb82"Tue Feb 15 07:49:29 2022 : Debug: (5) Service-Type = Framed-UserTue Feb 15 07:49:29 2022 : Debug: (5) Framed-MTU = 1100Tue Feb 15 07:49:29 2022 : Debug: (5) EAP-Message = 0x020e000f01657269632e726f676572Tue Feb 15 07:49:29 2022 : Debug: (5) Aruba-Essid-Name = "Test"Tue Feb 15 07:49:29 2022 : Debug: (5) Aruba-Location-Id = "AP14"Tue Feb 15 07:49:29 2022 : Debug: (5) Aruba-AP-Group = "Ctrl-Wlan-Clement ADER-BYOD1"Tue Feb 15 07:49:29 2022 : Debug: (5) Aruba-Device-Type = "NOFP"Tue Feb 15 07:49:29 2022 : Debug: (5) Message-Authenticator = 0xef844d30fba690aa52b8356793a00cc7Tue Feb 15 07:49:29 2022 : Debug: (5) session-state: No State attributeTue Feb 15 07:49:29 2022 : Debug: (5) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:29 2022 : Debug: (5) authorize {Tue Feb 15 07:49:29 2022 : Debug: (5) policy filter_username {Tue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name) {Tue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name) -> TRUETue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name) {Tue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ / /) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ / /) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /\.\./ ) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /\.\./ ) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /\.$/) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /\.$/) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /@\./) {Tue Feb 15 07:49:29 2022 : Debug: No matchesTue Feb 15 07:49:29 2022 : Debug: (5) if (&User-Name =~ /@\./) -> FALSETue Feb 15 07:49:29 2022 : Debug: (5) } # if (&User-Name) = notfoundTue Feb 15 07:49:29 2022 : Debug: (5) } # policy filter_username = notfoundTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling preprocess (rlm_preprocess)Tue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from preprocess (rlm_preprocess)Tue Feb 15 07:49:29 2022 : Debug: (5) [preprocess] = okTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling chap (rlm_chap)Tue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from chap (rlm_chap)Tue Feb 15 07:49:29 2022 : Debug: (5) [chap] = noopTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling mschap (rlm_mschap)Tue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from mschap (rlm_mschap)Tue Feb 15 07:49:29 2022 : Debug: (5) [mschap] = noopTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling digest (rlm_digest)Tue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from digest (rlm_digest)Tue Feb 15 07:49:29 2022 : Debug: (5) [digest] = noopTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling suffix (rlm_realm)Tue Feb 15 07:49:29 2022 : Debug: (5) suffix: Checking for suffix after "@"Tue Feb 15 07:49:29 2022 : Debug: (5) suffix: No '@' in User-Name = "eric.roger", looking up realm NULLTue Feb 15 07:49:29 2022 : Debug: (5) suffix: Found realm "DEFAULT"Tue Feb 15 07:49:29 2022 : Debug: (5) suffix: Adding Realm = "DEFAULT"Tue Feb 15 07:49:29 2022 : Debug: (5) suffix: Authentication realm is LOCALTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from suffix (rlm_realm)Tue Feb 15 07:49:29 2022 : Debug: (5) [suffix] = okTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: calling eap (rlm_eap)Tue Feb 15 07:49:29 2022 : Debug: (5) eap: Peer sent EAP Response (code 2) ID 14 length 15Tue Feb 15 07:49:29 2022 : Debug: (5) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorizeTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap)Tue Feb 15 07:49:29 2022 : Debug: (5) [eap] = okTue Feb 15 07:49:29 2022 : Debug: (5) } # authorize = okTue Feb 15 07:49:29 2022 : Debug: (5) Found Auth-Type = eapTue Feb 15 07:49:29 2022 : Debug: (5) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:29 2022 : Debug: (5) authenticate {Tue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authenticate]: calling eap (rlm_eap)Tue Feb 15 07:49:29 2022 : Debug: (5) eap: Peer sent packet with method EAP Identity (1)Tue Feb 15 07:49:29 2022 : Debug: (5) eap: Calling submodule eap_ttls to process dataTue Feb 15 07:49:29 2022 : Debug: (5) eap_ttls: Initiating new EAP-TLS sessionTue Feb 15 07:49:29 2022 : Debug: (5) eap_ttls: [eaptls start] = requestTue Feb 15 07:49:29 2022 : Debug: (5) eap: Sending EAP Request (code 1) ID 15 length 6Tue Feb 15 07:49:29 2022 : Debug: (5) eap: EAP session adding &reply:State = 0xa12bcb1ba124de2cTue Feb 15 07:49:29 2022 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap)Tue Feb 15 07:49:29 2022 : Debug: (5) [eap] = handledTue Feb 15 07:49:29 2022 : Debug: (5) } # authenticate = handledTue Feb 15 07:49:29 2022 : Debug: (5) Using Post-Auth-Type ChallengeTue Feb 15 07:49:29 2022 : Debug: (5) # Executing group from file /etc/freeradius/3.0/sites-enabled/defaultTue Feb 15 07:49:29 2022 : Debug: (5) Challenge { ... } # empty sub-section is ignoredTue Feb 15 07:49:29 2022 : Debug: (5) session-state: Nothing to cacheTue Feb 15 07:49:29 2022 : Debug: (5) Sent Access-Challenge Id 159 from 172.16.1.232:1812 to 172.16.251.14:58115 length 0Tue Feb 15 07:49:29 2022 : Debug: (5) EAP-Message = 0x010f00061520Tue Feb 15 07:49:29 2022 : Debug: (5) Message-Authenticator = 0x00000000000000000000000000000000Tue Feb 15 07:49:29 2022 : Debug: (5) State = 0xa12bcb1ba124de2c4091bac68f71e368Tue Feb 15 07:49:29 2022 : Debug: (5) Finished requestTue Feb 15 07:49:29 2022 : Debug: Waking up in 3.6 seconds.