Accounting requests over TCP
I am configuring a virtual server to listen for authentication and accounting requests on TCP ports 2017 and 2018 respectively. When the request comes for the same host on 2018 (accounting port) I am seeing an error in radius log something like below. Please note all accounting messages are being successfully processed by virtual server. Mon Sep 19 16:24:23 2022 : Error: Failed inserting TCP socket into parent list. Mon Sep 19 16:24:23 2022 : Info: ... adding new socket acct from client (20 8.59.110.70, 45060) -> (*, 2018) Mon Sep 19 16:24:23 2022 : Info: ... shutting down socket acct from client (208.59.110.70, 45060) -> (*, 2018) freeradius logs in debug mode. Mon Sep 19 17:27:08 2022 : Debug: Server was built with: Mon Sep 19 17:27:08 2022 : Debug: accounting : yes Mon Sep 19 17:27:08 2022 : Debug: authentication : yes Mon Sep 19 17:27:08 2022 : Debug: ascend-binary-attributes : yes Mon Sep 19 17:27:08 2022 : Debug: coa : yes Mon Sep 19 17:27:08 2022 : Debug: control-socket : yes Mon Sep 19 17:27:08 2022 : Debug: detail : yes Mon Sep 19 17:27:08 2022 : Debug: dhcp : yes Mon Sep 19 17:27:08 2022 : Debug: dynamic-clients : yes Mon Sep 19 17:27:08 2022 : Debug: osfc2 : no Mon Sep 19 17:27:08 2022 : Debug: proxy : yes Mon Sep 19 17:27:08 2022 : Debug: regex-pcre : no Mon Sep 19 17:27:08 2022 : Debug: regex-posix : yes Mon Sep 19 17:27:08 2022 : Debug: regex-posix-extended : yes Mon Sep 19 17:27:08 2022 : Debug: session-management : yes Mon Sep 19 17:27:08 2022 : Debug: stats : yes Mon Sep 19 17:27:08 2022 : Debug: systemd : yes Mon Sep 19 17:27:08 2022 : Debug: tcp : yes Mon Sep 19 17:27:08 2022 : Debug: threads : yes Mon Sep 19 17:27:08 2022 : Debug: tls : yes Mon Sep 19 17:27:08 2022 : Debug: unlang : yes Mon Sep 19 17:27:08 2022 : Debug: vmps : yes Mon Sep 19 17:27:08 2022 : Debug: developer : no Mon Sep 19 17:27:08 2022 : Debug: Server core libs: Mon Sep 19 17:27:08 2022 : Debug: freeradius-server : 3.0.26 Mon Sep 19 17:27:08 2022 : Debug: talloc : 2.3.* Mon Sep 19 17:27:08 2022 : Debug: ssl : 1.1.1f release Mon Sep 19 17:27:08 2022 : Debug: Endianness: Mon Sep 19 17:27:08 2022 : Debug: little Mon Sep 19 17:27:08 2022 : Debug: Compilation flags: Mon Sep 19 17:27:08 2022 : Debug: cppflags : -Wdate-time -D_FORTIFY_SOURCE=2 Mon Sep 19 17:27:08 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 -g -O2 -fdebug-prefix-map=/radsec/freeradius-server=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2 -O2 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -DNDEBUG -DIS_MODULE=1 Mon Sep 19 17:27:08 2022 : Debug: ldflags : -Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now Mon Sep 19 17:27:08 2022 : Debug: libs : -lcrypto -lssl -ltalloc -latomic -lcap -lnsl -lresolv -ldl -lpthread -lreadline Mon Sep 19 17:27:08 2022 : Debug: Mon Sep 19 17:27:08 2022 : Info: FreeRADIUS Version 3.0.26 Mon Sep 19 17:27:08 2022 : Info: Copyright (C) 1999-2021 The FreeRADIUS server project and contributors Mon Sep 19 17:27:08 2022 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Mon Sep 19 17:27:08 2022 : Info: PARTICULAR PURPOSE Mon Sep 19 17:27:08 2022 : Info: You may redistribute copies of FreeRADIUS under the terms of the Mon Sep 19 17:27:08 2022 : Info: GNU General Public License Mon Sep 19 17:27:08 2022 : Info: For more information about these matters, see the file named COPYRIGHT Mon Sep 19 17:27:08 2022 : Info: Starting - reading configuration files ... Mon Sep 19 17:27:08 2022 : Debug: including dictionary file /usr/share/freeradius/dictionary Mon Sep 19 17:27:08 2022 : Debug: including dictionary file /usr/share/freeradius/dictionary.dhcp Mon Sep 19 17:27:08 2022 : Debug: including dictionary file /usr/share/freeradius/dictionary.vqp Mon Sep 19 17:27:08 2022 : Debug: including dictionary file /etc/freeradius/dictionary Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/radiusd.conf Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/proxy.conf Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/clients.conf Mon Sep 19 17:27:08 2022 : Debug: including files in directory /etc/freeradius/mods-enabled/ Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/replicate Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/unpack Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/exec Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/detail Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/pap Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/chap Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/ntlm_auth Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/radutmp Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/sradutmp Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/expr Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/utf8 Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/expiration Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/unix Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/dynamic_clients Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/mschap Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/files Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/totp Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/logintime Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/passwd Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/echo Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/preprocess Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/soh Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/linelog Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/digest Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/mods-enabled/date Mon Sep 19 17:27:08 2022 : Debug: including files in directory /etc/freeradius/policy.d/ Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/filter Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/eap Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/moonshot-targeted-ids Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/abfab-tr Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/debug Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/canonicalization Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/control Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/rfc7542 Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/cui Mon Sep 19 17:27:08 2022 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Mon Sep 19 17:27:08 2022 : Debug: OPTIMIZING (no == yes) --> FALSE Mon Sep 19 17:27:08 2022 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Mon Sep 19 17:27:08 2022 : Debug: OPTIMIZING (no == yes) --> FALSE Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/dhcp Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/accounting Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/policy.d/operator-name Mon Sep 19 17:27:08 2022 : Debug: including files in directory /etc/freeradius/sites-enabled/ Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/sites-enabled/tcpServer Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/clients.conf Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/sites-enabled/passpoint Mon Sep 19 17:27:08 2022 : Debug: including configuration file /etc/freeradius/clients.conf Mon Sep 19 17:27:08 2022 : Debug: main { Mon Sep 19 17:27:08 2022 : Debug: security { Mon Sep 19 17:27:08 2022 : Debug: user = "freerad" Mon Sep 19 17:27:08 2022 : Debug: group = "freerad" Mon Sep 19 17:27:08 2022 : Debug: allow_core_dumps = yes Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[484]: The item 'max_attributes' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[502]: The item 'reject_delay' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[522]: The item 'status_server' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Debug: name = "freeradius" Mon Sep 19 17:27:08 2022 : Debug: prefix = "/usr" Mon Sep 19 17:27:08 2022 : Debug: localstatedir = "/var" Mon Sep 19 17:27:08 2022 : Debug: logdir = "/var/log/freeradius" Mon Sep 19 17:27:08 2022 : Debug: run_dir = "/var/run/freeradius" Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[73]: The item 'secretKey' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[74]: The item 'greEndpointIp' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[80]: The item 'db_dir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[83]: The item 'eapCorrEnabled' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[86]: The item 'accountingServer' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[87]: The item 'accountingServerEnabled' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[120]: The item 'libdir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[131]: The item 'pidfile' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[152]: The item 'correct_escapes' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[206]: The item 'max_request_time' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[225]: The item 'cleanup_delay' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[244]: The item 'max_requests' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[262]: The item 'hostname_lookups' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[268]: The item 'regular_expressions' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[269]: The item 'extended_expressions' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[272]: The item 'delete_blocked_requests' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[394]: The item 'checkrad' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[527]: The item 'usercollide' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[530]: The item 'lower_user' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[531]: The item 'lower_pass' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[532]: The item 'nospace_user' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[533]: The item 'nospace_pass' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[552]: The item 'proxy_requests' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Info: Core dumps are enabled Mon Sep 19 17:27:08 2022 : Debug: main { Mon Sep 19 17:27:08 2022 : Debug: name = "freeradius" Mon Sep 19 17:27:08 2022 : Debug: prefix = "/usr" Mon Sep 19 17:27:08 2022 : Debug: localstatedir = "/var" Mon Sep 19 17:27:08 2022 : Debug: sbindir = "/usr/sbin" Mon Sep 19 17:27:08 2022 : Debug: logdir = "/var/log/freeradius" Mon Sep 19 17:27:08 2022 : Debug: run_dir = "/var/run/freeradius" Mon Sep 19 17:27:08 2022 : Debug: libdir = "/usr/lib/freeradius" Mon Sep 19 17:27:08 2022 : Debug: radacctdir = "/var/log/freeradius/radacct" Mon Sep 19 17:27:08 2022 : Debug: hostname_lookups = no Mon Sep 19 17:27:08 2022 : Debug: max_request_time = 30 Mon Sep 19 17:27:08 2022 : Debug: cleanup_delay = 5 Mon Sep 19 17:27:08 2022 : Debug: max_requests = 16384 Mon Sep 19 17:27:08 2022 : Debug: postauth_client_lost = no Mon Sep 19 17:27:08 2022 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Mon Sep 19 17:27:08 2022 : Debug: checkrad = "/usr/sbin/checkrad" Mon Sep 19 17:27:08 2022 : Debug: debug_level = 0 Mon Sep 19 17:27:08 2022 : Debug: proxy_requests = yes Mon Sep 19 17:27:08 2022 : Debug: log { Mon Sep 19 17:27:08 2022 : Debug: stripped_names = no Mon Sep 19 17:27:08 2022 : Debug: auth = yes Mon Sep 19 17:27:08 2022 : Debug: auth_badpass = no Mon Sep 19 17:27:08 2022 : Debug: auth_goodpass = no Mon Sep 19 17:27:08 2022 : Debug: colourise = yes Mon Sep 19 17:27:08 2022 : Debug: msg_denied = "You are already logged in - access denied" Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[290]: The item 'destination' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[307]: The item 'file' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[353]: The item 'syslog_facility' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Debug: resources { Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Debug: security { Mon Sep 19 17:27:08 2022 : Debug: max_attributes = 200 Mon Sep 19 17:27:08 2022 : Debug: reject_delay = 1.000000 Mon Sep 19 17:27:08 2022 : Debug: status_server = yes Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[55]: The item 'sysconfdir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[70]: The item 'cadir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[73]: The item 'secretKey' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[74]: The item 'greEndpointIp' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[80]: The item 'db_dir' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[83]: The item 'eapCorrEnabled' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[86]: The item 'accountingServer' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[87]: The item 'accountingServerEnabled' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[152]: The item 'correct_escapes' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[268]: The item 'regular_expressions' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[269]: The item 'extended_expressions' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[272]: The item 'delete_blocked_requests' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[527]: The item 'usercollide' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[530]: The item 'lower_user' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[531]: The item 'lower_pass' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[532]: The item 'nospace_user' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/radiusd.conf[533]: The item 'nospace_pass' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Debug: radiusd: #### Loading Realms and Home Servers #### Mon Sep 19 17:27:08 2022 : Debug: proxy server { Mon Sep 19 17:27:08 2022 : Debug: retry_delay = 5 Mon Sep 19 17:27:08 2022 : Debug: retry_count = 3 Mon Sep 19 17:27:08 2022 : Debug: default_fallback = no Mon Sep 19 17:27:08 2022 : Debug: dead_time = 120 Mon Sep 19 17:27:08 2022 : Debug: wake_all_if_all_dead = no Mon Sep 19 17:27:08 2022 : Warning: /etc/freeradius/proxy.conf[5]: The item 'post_proxy_authorize' is defined, but is unused by the configuration Mon Sep 19 17:27:08 2022 : Debug: } Mon Sep 19 17:27:08 2022 : Debug: home_server testHome { Mon Sep 19 17:27:13 2022 : Debug: ipaddr = testHome IPv4 address [216.58.255.72] Mon Sep 19 17:27:13 2022 : Debug: port = 2017 Mon Sep 19 17:27:13 2022 : Debug: type = "auth" Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: secret = "testsecret" Mon Sep 19 17:27:13 2022 : Debug: response_window = 30.000000 Mon Sep 19 17:27:13 2022 : Debug: response_timeouts = 1 Mon Sep 19 17:27:13 2022 : Debug: max_outstanding = 65536 Mon Sep 19 17:27:13 2022 : Debug: zombie_period = 20 Mon Sep 19 17:27:13 2022 : Debug: status_check = "none" Mon Sep 19 17:27:13 2022 : Debug: ping_interval = 30 Mon Sep 19 17:27:13 2022 : Debug: check_timeout = 4 Mon Sep 19 17:27:13 2022 : Debug: num_answers_to_alive = 3 Mon Sep 19 17:27:13 2022 : Debug: revive_interval = 60 Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: max_requests = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 480 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: coa { Mon Sep 19 17:27:13 2022 : Debug: irt = 2 Mon Sep 19 17:27:13 2022 : Debug: mrt = 16 Mon Sep 19 17:27:13 2022 : Debug: mrc = 5 Mon Sep 19 17:27:13 2022 : Debug: mrd = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Warning: Ignoring "zombie_period = 20", forcing to "zombie_period = 30" Mon Sep 19 17:27:13 2022 : Debug: home_server testHome2 { Mon Sep 19 17:27:13 2022 : Debug: ipaddr = testHome2 IPv4 address [216.58.255.69] Mon Sep 19 17:27:13 2022 : Debug: port = 2017 Mon Sep 19 17:27:13 2022 : Debug: type = "auth" Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: secret = "testsecret" Mon Sep 19 17:27:13 2022 : Debug: response_window = 30.000000 Mon Sep 19 17:27:13 2022 : Debug: response_timeouts = 1 Mon Sep 19 17:27:13 2022 : Debug: max_outstanding = 65536 Mon Sep 19 17:27:13 2022 : Debug: zombie_period = 20 Mon Sep 19 17:27:13 2022 : Debug: status_check = "none" Mon Sep 19 17:27:13 2022 : Debug: ping_interval = 30 Mon Sep 19 17:27:13 2022 : Debug: check_timeout = 4 Mon Sep 19 17:27:13 2022 : Debug: num_answers_to_alive = 3 Mon Sep 19 17:27:13 2022 : Debug: revive_interval = 60 Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: max_requests = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 480 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: coa { Mon Sep 19 17:27:13 2022 : Debug: irt = 2 Mon Sep 19 17:27:13 2022 : Debug: mrt = 16 Mon Sep 19 17:27:13 2022 : Debug: mrc = 5 Mon Sep 19 17:27:13 2022 : Debug: mrd = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Warning: Ignoring "zombie_period = 20", forcing to "zombie_period = 30" Mon Sep 19 17:27:13 2022 : Debug: home_server testHome3 { Mon Sep 19 17:27:13 2022 : Debug: ipaddr = testHome3 IPv4 address [216.58.255.70] Mon Sep 19 17:27:13 2022 : Debug: port = 2017 Mon Sep 19 17:27:13 2022 : Debug: type = "auth" Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: secret = "testsecret" Mon Sep 19 17:27:13 2022 : Debug: response_window = 30.000000 Mon Sep 19 17:27:13 2022 : Debug: response_timeouts = 1 Mon Sep 19 17:27:13 2022 : Debug: max_outstanding = 65536 Mon Sep 19 17:27:13 2022 : Debug: zombie_period = 20 Mon Sep 19 17:27:13 2022 : Debug: status_check = "none" Mon Sep 19 17:27:13 2022 : Debug: ping_interval = 30 Mon Sep 19 17:27:13 2022 : Debug: check_timeout = 4 Mon Sep 19 17:27:13 2022 : Debug: num_answers_to_alive = 3 Mon Sep 19 17:27:13 2022 : Debug: revive_interval = 60 Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: max_requests = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 480 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: coa { Mon Sep 19 17:27:13 2022 : Debug: irt = 2 Mon Sep 19 17:27:13 2022 : Debug: mrt = 16 Mon Sep 19 17:27:13 2022 : Debug: mrc = 5 Mon Sep 19 17:27:13 2022 : Debug: mrd = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Warning: Ignoring "zombie_period = 20", forcing to "zombie_period = 30" Mon Sep 19 17:27:13 2022 : Debug: home_server_pool passpoint { Mon Sep 19 17:27:13 2022 : Debug: type = keyed-balance Mon Sep 19 17:27:13 2022 : Debug: home_server = testHome2 Mon Sep 19 17:27:13 2022 : Debug: home_server = testHome2 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: realm to_datacenter_passpoint_auth { Mon Sep 19 17:27:13 2022 : Debug: auth_pool = passpoint Mon Sep 19 17:27:13 2022 : Debug: nostrip Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: radiusd: #### Loading Clients #### Mon Sep 19 17:27:13 2022 : Debug: client tcpClient { Mon Sep 19 17:27:13 2022 : Debug: ipaddr = 216.58.255.0/24 Mon Sep 19 17:27:13 2022 : Debug: require_message_authenticator = no Mon Sep 19 17:27:13 2022 : Debug: secret = "testsecret" Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Adding client 216.58.255.0/24 (216.58.255.0) to prefix tree 24 Mon Sep 19 17:27:13 2022 : Info: Debug state unknown (cap_sys_ptrace capability not set) Mon Sep 19 17:27:13 2022 : Info: systemd watchdog is disabled Mon Sep 19 17:27:13 2022 : Debug: # Creating Auth-Type = OK Mon Sep 19 17:27:13 2022 : Debug: # Creating Auth-Type = EAP Mon Sep 19 17:27:13 2022 : Debug: radiusd: #### Instantiating modules #### Mon Sep 19 17:27:13 2022 : Debug: modules { Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_replicate with path: /usr/lib/freeradius/rlm_replicate.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_replicate, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_replicate Mon Sep 19 17:27:13 2022 : Debug: # Loading module "replicate" from file /etc/freeradius/mods-enabled/replicate Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_unpack with path: /usr/lib/freeradius/rlm_unpack.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_unpack, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_unpack Mon Sep 19 17:27:13 2022 : Debug: # Loading module "unpack" from file /etc/freeradius/mods-enabled/unpack Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_exec, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_exec Mon Sep 19 17:27:13 2022 : Debug: # Loading module "exec" from file /etc/freeradius/mods-enabled/exec Mon Sep 19 17:27:13 2022 : Debug: exec { Mon Sep 19 17:27:13 2022 : Debug: wait = no Mon Sep 19 17:27:13 2022 : Debug: input_pairs = "request" Mon Sep 19 17:27:13 2022 : Debug: shell_escape = yes Mon Sep 19 17:27:13 2022 : Debug: timeout = 10 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_detail, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_detail Mon Sep 19 17:27:13 2022 : Debug: # Loading module "detail" from file /etc/freeradius/mods-enabled/detail Mon Sep 19 17:27:13 2022 : Debug: detail { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Mon Sep 19 17:27:13 2022 : Debug: header = "%t" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: locking = no Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: log_packet_header = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_pap, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_pap Mon Sep 19 17:27:13 2022 : Debug: # Loading module "pap" from file /etc/freeradius/mods-enabled/pap Mon Sep 19 17:27:13 2022 : Debug: pap { Mon Sep 19 17:27:13 2022 : Debug: normalise = yes Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_chap, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_chap Mon Sep 19 17:27:13 2022 : Debug: # Loading module "chap" from file /etc/freeradius/mods-enabled/chap Mon Sep 19 17:27:13 2022 : Debug: # Loading module "ntlm_auth" from file /etc/freeradius/mods-enabled/ntlm_auth Mon Sep 19 17:27:13 2022 : Debug: exec ntlm_auth { Mon Sep 19 17:27:13 2022 : Debug: wait = yes Mon Sep 19 17:27:13 2022 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Mon Sep 19 17:27:13 2022 : Debug: shell_escape = yes Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_radutmp with path: /usr/lib/freeradius/rlm_radutmp.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_radutmp, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_radutmp Mon Sep 19 17:27:13 2022 : Debug: # Loading module "radutmp" from file /etc/freeradius/mods-enabled/radutmp Mon Sep 19 17:27:13 2022 : Debug: radutmp { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radutmp" Mon Sep 19 17:27:13 2022 : Debug: username = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: case_sensitive = yes Mon Sep 19 17:27:13 2022 : Debug: check_with_nas = yes Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: caller_id = yes Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "sradutmp" from file /etc/freeradius/mods-enabled/sradutmp Mon Sep 19 17:27:13 2022 : Debug: radutmp sradutmp { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/sradutmp" Mon Sep 19 17:27:13 2022 : Debug: username = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: case_sensitive = yes Mon Sep 19 17:27:13 2022 : Debug: check_with_nas = yes Mon Sep 19 17:27:13 2022 : Debug: permissions = 420 Mon Sep 19 17:27:13 2022 : Debug: caller_id = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_realm with path: /usr/lib/freeradius/rlm_realm.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_realm, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_realm Mon Sep 19 17:27:13 2022 : Debug: # Loading module "IPASS" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: realm IPASS { Mon Sep 19 17:27:13 2022 : Debug: format = "prefix" Mon Sep 19 17:27:13 2022 : Debug: delimiter = "/" Mon Sep 19 17:27:13 2022 : Debug: ignore_default = no Mon Sep 19 17:27:13 2022 : Debug: ignore_null = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "suffix" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: realm suffix { Mon Sep 19 17:27:13 2022 : Debug: format = "suffix" Mon Sep 19 17:27:13 2022 : Debug: delimiter = "@" Mon Sep 19 17:27:13 2022 : Debug: ignore_default = no Mon Sep 19 17:27:13 2022 : Debug: ignore_null = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "bangpath" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: realm bangpath { Mon Sep 19 17:27:13 2022 : Debug: format = "prefix" Mon Sep 19 17:27:13 2022 : Debug: delimiter = "!" Mon Sep 19 17:27:13 2022 : Debug: ignore_default = no Mon Sep 19 17:27:13 2022 : Debug: ignore_null = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "realmpercent" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: realm realmpercent { Mon Sep 19 17:27:13 2022 : Debug: format = "suffix" Mon Sep 19 17:27:13 2022 : Debug: delimiter = "%" Mon Sep 19 17:27:13 2022 : Debug: ignore_default = no Mon Sep 19 17:27:13 2022 : Debug: ignore_null = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "ntdomain" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: realm ntdomain { Mon Sep 19 17:27:13 2022 : Debug: format = "prefix" Mon Sep 19 17:27:13 2022 : Debug: delimiter = "\\" Mon Sep 19 17:27:13 2022 : Debug: ignore_default = no Mon Sep 19 17:27:13 2022 : Debug: ignore_null = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_expr, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_expr Mon Sep 19 17:27:13 2022 : Debug: # Loading module "expr" from file /etc/freeradius/mods-enabled/expr Mon Sep 19 17:27:13 2022 : Debug: expr { Mon Sep 19 17:27:13 2022 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "auth_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: detail auth_log { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Mon Sep 19 17:27:13 2022 : Debug: header = "%t" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: locking = no Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: log_packet_header = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "reply_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: detail reply_log { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Mon Sep 19 17:27:13 2022 : Debug: header = "%t" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: locking = no Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: log_packet_header = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: detail pre_proxy_log { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Mon Sep 19 17:27:13 2022 : Debug: header = "%t" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: locking = no Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: log_packet_header = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: detail post_proxy_log { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Mon Sep 19 17:27:13 2022 : Debug: header = "%t" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: locking = no Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: log_packet_header = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_attr_filter with path: /usr/lib/freeradius/rlm_attr_filter.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_attr_filter, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_attr_filter Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.post-proxy { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/post-proxy" Mon Sep 19 17:27:13 2022 : Debug: key = "%{Realm}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.pre-proxy { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/pre-proxy" Mon Sep 19 17:27:13 2022 : Debug: key = "%{Realm}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.access_reject { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/access_reject" Mon Sep 19 17:27:13 2022 : Debug: key = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.access_challenge { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/access_challenge" Mon Sep 19 17:27:13 2022 : Debug: key = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.accounting_response { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/accounting_response" Mon Sep 19 17:27:13 2022 : Debug: key = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "attr_filter.coa" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: attr_filter attr_filter.coa { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/attr_filter/coa" Mon Sep 19 17:27:13 2022 : Debug: key = "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: relaxed = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_utf8 with path: /usr/lib/freeradius/rlm_utf8.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_utf8, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_utf8 Mon Sep 19 17:27:13 2022 : Debug: # Loading module "utf8" from file /etc/freeradius/mods-enabled/utf8 Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_expiration with path: /usr/lib/freeradius/rlm_expiration.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_expiration, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_expiration Mon Sep 19 17:27:13 2022 : Debug: # Loading module "expiration" from file /etc/freeradius/mods-enabled/expiration Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_unix with path: /usr/lib/freeradius/rlm_unix.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_unix, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_unix Mon Sep 19 17:27:13 2022 : Debug: # Loading module "unix" from file /etc/freeradius/mods-enabled/unix Mon Sep 19 17:27:13 2022 : Debug: unix { Mon Sep 19 17:27:13 2022 : Debug: radwtmp = "/var/log/freeradius/radwtmp" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Creating attribute Unix-Group Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_dynamic_clients with path: /usr/lib/freeradius/rlm_dynamic_clients.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_dynamic_clients, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_dynamic_clients Mon Sep 19 17:27:13 2022 : Debug: # Loading module "dynamic_clients" from file /etc/freeradius/mods-enabled/dynamic_clients Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_mschap with path: /usr/lib/freeradius/rlm_mschap.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_mschap, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_mschap Mon Sep 19 17:27:13 2022 : Debug: # Loading module "mschap" from file /etc/freeradius/mods-enabled/mschap Mon Sep 19 17:27:13 2022 : Debug: mschap { Mon Sep 19 17:27:13 2022 : Debug: use_mppe = yes Mon Sep 19 17:27:13 2022 : Debug: require_encryption = no Mon Sep 19 17:27:13 2022 : Debug: require_strong = no Mon Sep 19 17:27:13 2022 : Debug: with_ntdomain_hack = yes Mon Sep 19 17:27:13 2022 : Debug: passchange { Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: allow_retry = yes Mon Sep 19 17:27:13 2022 : Debug: winbind_retry_with_normalised_username = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_files with path: /usr/lib/freeradius/rlm_files.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_files, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_files Mon Sep 19 17:27:13 2022 : Debug: # Loading module "files" from file /etc/freeradius/mods-enabled/files Mon Sep 19 17:27:13 2022 : Debug: files { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/freeradius/mods-config/files/authorize" Mon Sep 19 17:27:13 2022 : Debug: acctusersfile = "/etc/freeradius/mods-config/files/accounting" Mon Sep 19 17:27:13 2022 : Debug: preproxy_usersfile = "/etc/freeradius/mods-config/files/pre-proxy" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_always with path: /usr/lib/freeradius/rlm_always.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_always, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_always Mon Sep 19 17:27:13 2022 : Debug: # Loading module "reject" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always reject { Mon Sep 19 17:27:13 2022 : Debug: rcode = "reject" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "fail" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always fail { Mon Sep 19 17:27:13 2022 : Debug: rcode = "fail" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "ok" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always ok { Mon Sep 19 17:27:13 2022 : Debug: rcode = "ok" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "handled" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always handled { Mon Sep 19 17:27:13 2022 : Debug: rcode = "handled" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "invalid" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always invalid { Mon Sep 19 17:27:13 2022 : Debug: rcode = "invalid" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "userlock" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always userlock { Mon Sep 19 17:27:13 2022 : Debug: rcode = "userlock" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "notfound" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always notfound { Mon Sep 19 17:27:13 2022 : Debug: rcode = "notfound" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "noop" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always noop { Mon Sep 19 17:27:13 2022 : Debug: rcode = "noop" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "updated" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: always updated { Mon Sep 19 17:27:13 2022 : Debug: rcode = "updated" Mon Sep 19 17:27:13 2022 : Debug: simulcount = 0 Mon Sep 19 17:27:13 2022 : Debug: mpp = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_totp with path: /usr/lib/freeradius/rlm_totp.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_totp, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_totp Mon Sep 19 17:27:13 2022 : Debug: # Loading module "totp" from file /etc/freeradius/mods-enabled/totp Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_logintime with path: /usr/lib/freeradius/rlm_logintime.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_logintime, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_logintime Mon Sep 19 17:27:13 2022 : Debug: # Loading module "logintime" from file /etc/freeradius/mods-enabled/logintime Mon Sep 19 17:27:13 2022 : Debug: logintime { Mon Sep 19 17:27:13 2022 : Debug: minimum_timeout = 60 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_passwd with path: /usr/lib/freeradius/rlm_passwd.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_passwd, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_passwd Mon Sep 19 17:27:13 2022 : Debug: # Loading module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd Mon Sep 19 17:27:13 2022 : Debug: passwd etc_passwd { Mon Sep 19 17:27:13 2022 : Debug: filename = "/etc/passwd" Mon Sep 19 17:27:13 2022 : Debug: format = "*User-Name:Crypt-Password:" Mon Sep 19 17:27:13 2022 : Debug: delimiter = ":" Mon Sep 19 17:27:13 2022 : Debug: ignore_nislike = no Mon Sep 19 17:27:13 2022 : Debug: ignore_empty = yes Mon Sep 19 17:27:13 2022 : Debug: allow_multiple_keys = no Mon Sep 19 17:27:13 2022 : Debug: hash_size = 100 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "echo" from file /etc/freeradius/mods-enabled/echo Mon Sep 19 17:27:13 2022 : Debug: exec echo { Mon Sep 19 17:27:13 2022 : Debug: wait = yes Mon Sep 19 17:27:13 2022 : Debug: program = "/bin/echo %{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: input_pairs = "request" Mon Sep 19 17:27:13 2022 : Debug: output_pairs = "reply" Mon Sep 19 17:27:13 2022 : Debug: shell_escape = yes Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_preprocess, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_preprocess Mon Sep 19 17:27:13 2022 : Debug: # Loading module "preprocess" from file /etc/freeradius/mods-enabled/preprocess Mon Sep 19 17:27:13 2022 : Debug: preprocess { Mon Sep 19 17:27:13 2022 : Debug: huntgroups = "/etc/freeradius/mods-config/preprocess/huntgroups" Mon Sep 19 17:27:13 2022 : Debug: hints = "/etc/freeradius/mods-config/preprocess/hints" Mon Sep 19 17:27:13 2022 : Debug: with_ascend_hack = no Mon Sep 19 17:27:13 2022 : Debug: ascend_channels_per_line = 23 Mon Sep 19 17:27:13 2022 : Debug: with_ntdomain_hack = no Mon Sep 19 17:27:13 2022 : Debug: with_specialix_jetstream_hack = no Mon Sep 19 17:27:13 2022 : Debug: with_cisco_vsa_hack = no Mon Sep 19 17:27:13 2022 : Debug: with_alvarion_vsa_hack = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_soh with path: /usr/lib/freeradius/rlm_soh.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_soh, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_soh Mon Sep 19 17:27:13 2022 : Debug: # Loading module "soh" from file /etc/freeradius/mods-enabled/soh Mon Sep 19 17:27:13 2022 : Debug: soh { Mon Sep 19 17:27:13 2022 : Debug: dhcp = yes Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_linelog with path: /usr/lib/freeradius/rlm_linelog.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_linelog, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_linelog Mon Sep 19 17:27:13 2022 : Debug: # Loading module "linelog" from file /etc/freeradius/mods-enabled/linelog Mon Sep 19 17:27:13 2022 : Debug: linelog { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/linelog" Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: syslog_severity = "info" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: format = "This is a log message for %{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "log_accounting" from file /etc/freeradius/mods-enabled/linelog Mon Sep 19 17:27:13 2022 : Debug: linelog log_accounting { Mon Sep 19 17:27:13 2022 : Debug: filename = "/var/log/freeradius/linelog-accounting" Mon Sep 19 17:27:13 2022 : Debug: escape_filenames = no Mon Sep 19 17:27:13 2022 : Debug: syslog_severity = "info" Mon Sep 19 17:27:13 2022 : Debug: permissions = 384 Mon Sep 19 17:27:13 2022 : Debug: format = "" Mon Sep 19 17:27:13 2022 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_digest with path: /usr/lib/freeradius/rlm_digest.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_digest, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_digest Mon Sep 19 17:27:13 2022 : Debug: # Loading module "digest" from file /etc/freeradius/mods-enabled/digest Mon Sep 19 17:27:13 2022 : Debug: Loading rlm_date with path: /usr/lib/freeradius/rlm_date.so Mon Sep 19 17:27:13 2022 : Debug: Loaded rlm_date, checking if it's valid Mon Sep 19 17:27:13 2022 : Debug: # Loaded module rlm_date Mon Sep 19 17:27:13 2022 : Debug: # Loading module "date" from file /etc/freeradius/mods-enabled/date Mon Sep 19 17:27:13 2022 : Debug: date { Mon Sep 19 17:27:13 2022 : Debug: format = "%b %e %Y %H:%M:%S %Z" Mon Sep 19 17:27:13 2022 : Debug: utc = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Loading module "wispr2date" from file /etc/freeradius/mods-enabled/date Mon Sep 19 17:27:13 2022 : Debug: date wispr2date { Mon Sep 19 17:27:13 2022 : Debug: format = "%Y-%m-%dT%H:%M:%S" Mon Sep 19 17:27:13 2022 : Debug: utc = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: instantiate { Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "detail" from file /etc/freeradius/mods-enabled/detail Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "pap" from file /etc/freeradius/mods-enabled/pap Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "IPASS" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "suffix" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "bangpath" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "realmpercent" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "ntdomain" from file /etc/freeradius/mods-enabled/realm Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "auth_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "reply_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/post-proxy Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/pre-proxy Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/access_reject Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/access_challenge Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/accounting_response Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "attr_filter.coa" from file /etc/freeradius/mods-enabled/attr_filter Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/attr_filter/coa Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "expiration" from file /etc/freeradius/mods-enabled/expiration Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "mschap" from file /etc/freeradius/mods-enabled/mschap Mon Sep 19 17:27:13 2022 : Debug: rlm_mschap (mschap): using internal authentication Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "files" from file /etc/freeradius/mods-enabled/files Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/files/authorize Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/files/accounting Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/files/pre-proxy Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "reject" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "fail" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "ok" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "handled" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "invalid" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "userlock" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "notfound" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "noop" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "updated" from file /etc/freeradius/mods-enabled/always Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "logintime" from file /etc/freeradius/mods-enabled/logintime Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd Mon Sep 19 17:27:13 2022 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/mods-enabled/preprocess Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/preprocess/huntgroups Mon Sep 19 17:27:13 2022 : Debug: reading pairlist file /etc/freeradius/mods-config/preprocess/hints Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "linelog" from file /etc/freeradius/mods-enabled/linelog Mon Sep 19 17:27:13 2022 : Debug: # Instantiating module "log_accounting" from file /etc/freeradius/mods-enabled/linelog Mon Sep 19 17:27:13 2022 : Debug: } # modules Mon Sep 19 17:27:13 2022 : Debug: radiusd: #### Loading Virtual Servers #### Mon Sep 19 17:27:13 2022 : Debug: server { # from file /etc/freeradius/radiusd.conf Mon Sep 19 17:27:13 2022 : Debug: } # server Mon Sep 19 17:27:13 2022 : Debug: server passpoint { # from file /etc/freeradius/sites-enabled/passpoint Mon Sep 19 17:27:13 2022 : Debug: authenticate { Mon Sep 19 17:27:13 2022 : Debug: Compiling Auth-Type OK for attr Auth-Type Mon Sep 19 17:27:13 2022 : Debug: group { Mon Sep 19 17:27:13 2022 : Debug: ok Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Compiling Auth-Type Reject for attr Auth-Type Mon Sep 19 17:27:13 2022 : Debug: group { Mon Sep 19 17:27:13 2022 : Debug: reject Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Compiling Auth-Type EAP for attr Auth-Type Mon Sep 19 17:27:13 2022 : Debug: group { Mon Sep 19 17:27:13 2022 : Debug: reject Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } # authenticate Mon Sep 19 17:27:13 2022 : Debug: authorize { Mon Sep 19 17:27:13 2022 : Warning: /etc/freeradius/sites-enabled/passpoint[76]: Please change attribute reference to '&Load-Balance-Key := ...' Mon Sep 19 17:27:13 2022 : Debug: update { Mon Sep 19 17:27:13 2022 : Debug: &control:Load-Balance-Key := "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: &control:Proxy-To-Realm := "to_datacenter_passpoint_auth" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } # authorize Mon Sep 19 17:27:13 2022 : Debug: accounting { Mon Sep 19 17:27:13 2022 : Warning: /etc/freeradius/sites-enabled/passpoint[96]: Please change attribute reference to '&Load-Balance-Key := ...' Mon Sep 19 17:27:13 2022 : Debug: update { Mon Sep 19 17:27:13 2022 : Debug: &control:Load-Balance-Key := "%{User-Name}" Mon Sep 19 17:27:13 2022 : Debug: &control:Proxy-To-Realm := "to_datacenter_passpoint_acct" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } # accounting Mon Sep 19 17:27:13 2022 : Debug: } # server passpoint Mon Sep 19 17:27:13 2022 : Debug: thread pool { Mon Sep 19 17:27:13 2022 : Debug: start_servers = 5 Mon Sep 19 17:27:13 2022 : Debug: max_servers = 256 Mon Sep 19 17:27:13 2022 : Debug: min_spare_servers = 3 Mon Sep 19 17:27:13 2022 : Debug: max_spare_servers = 10 Mon Sep 19 17:27:13 2022 : Debug: max_requests_per_server = 0 Mon Sep 19 17:27:13 2022 : Debug: cleanup_delay = 5 Mon Sep 19 17:27:13 2022 : Debug: max_queue_size = 65536 Mon Sep 19 17:27:13 2022 : Debug: auto_limit_acct = no Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Thread spawned new child 1. Total threads in pool: 1 Mon Sep 19 17:27:13 2022 : Debug: Thread 1 waiting to be assigned a request Mon Sep 19 17:27:13 2022 : Debug: Thread spawned new child 2. Total threads in pool: 2 Mon Sep 19 17:27:13 2022 : Debug: Thread spawned new child 3. Total threads in pool: 3 Mon Sep 19 17:27:13 2022 : Debug: Thread 3 waiting to be assigned a request Mon Sep 19 17:27:13 2022 : Debug: Thread spawned new child 4. Total threads in pool: 4 Mon Sep 19 17:27:13 2022 : Debug: Thread spawned new child 5. Total threads in pool: 5 Mon Sep 19 17:27:13 2022 : Debug: Thread pool initialized Mon Sep 19 17:27:13 2022 : Debug: Thread 4 waiting to be assigned a request Mon Sep 19 17:27:13 2022 : Debug: Thread 5 waiting to be assigned a request Mon Sep 19 17:27:13 2022 : Debug: Created signal pipe. Read end FD 5, write end FD 6 Mon Sep 19 17:27:13 2022 : Debug: radiusd: #### Opening IP addresses and Ports #### Mon Sep 19 17:27:13 2022 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Mon Sep 19 17:27:13 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 directory Mon Sep 19 17:27:13 2022 : Debug: Thread 2 waiting to be assigned a request Mon Sep 19 17:27:13 2022 : Debug: Loading library using linker search path(s) Mon Sep 19 17:27:13 2022 : Debug: Defaults : /lib:/usr/lib Mon Sep 19 17:27:13 2022 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Mon Sep 19 17:27:13 2022 : Debug: listen { Mon Sep 19 17:27:13 2022 : Debug: type = "auth" Mon Sep 19 17:27:13 2022 : Debug: virtual_server = "passpoint" Mon Sep 19 17:27:13 2022 : Debug: ipaddr = * Mon Sep 19 17:27:13 2022 : Debug: port = 2017 Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 0 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: clients = "tcpclients" Mon Sep 19 17:27:13 2022 : Debug: client tcpClient { Mon Sep 19 17:27:13 2022 : Debug: ipaddr = 216.58.255.0/24 Mon Sep 19 17:27:13 2022 : Debug: require_message_authenticator = no Mon Sep 19 17:27:13 2022 : Debug: secret = "testsecret" Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Adding client 216.58.255.0/24 (216.58.255.0) to prefix tree 24 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so Mon Sep 19 17:27:13 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 directory Mon Sep 19 17:27:13 2022 : Debug: Loading library using linker search path(s) Mon Sep 19 17:27:13 2022 : Debug: Defaults : /lib:/usr/lib Mon Sep 19 17:27:13 2022 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Mon Sep 19 17:27:13 2022 : Debug: listen { Mon Sep 19 17:27:13 2022 : Debug: type = "acct" Mon Sep 19 17:27:13 2022 : Debug: virtual_server = "passpoint" Mon Sep 19 17:27:13 2022 : Debug: ipaddr = * Mon Sep 19 17:27:13 2022 : Debug: port = 2018 Mon Sep 19 17:27:13 2022 : Debug: proto = "tcp" Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 0 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: clients = "tcpclients" Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading proto_auth with path: /usr/lib/freeradius/proto_auth.so Mon Sep 19 17:27:13 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 directory Mon Sep 19 17:27:13 2022 : Debug: Loading library using linker search path(s) Mon Sep 19 17:27:13 2022 : Debug: Defaults : /lib:/usr/lib Mon Sep 19 17:27:13 2022 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Mon Sep 19 17:27:13 2022 : Debug: listen { Mon Sep 19 17:27:13 2022 : Debug: type = "auth" Mon Sep 19 17:27:13 2022 : Debug: ipaddr = * Mon Sep 19 17:27:13 2022 : Debug: port = 1817 Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 0 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 0 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so Mon Sep 19 17:27:13 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 directory Mon Sep 19 17:27:13 2022 : Debug: Loading library using linker search path(s) Mon Sep 19 17:27:13 2022 : Debug: Defaults : /lib:/usr/lib Mon Sep 19 17:27:13 2022 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Mon Sep 19 17:27:13 2022 : Debug: listen { Mon Sep 19 17:27:13 2022 : Debug: type = "acct" Mon Sep 19 17:27:13 2022 : Debug: ipaddr = * Mon Sep 19 17:27:13 2022 : Debug: port = 1818 Mon Sep 19 17:27:13 2022 : Debug: limit { Mon Sep 19 17:27:13 2022 : Debug: max_connections = 16 Mon Sep 19 17:27:13 2022 : Debug: lifetime = 0 Mon Sep 19 17:27:13 2022 : Debug: idle_timeout = 30 Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: } Mon Sep 19 17:27:13 2022 : Debug: Listening on auth proto tcp address * port 2017 bound to server passpoint Mon Sep 19 17:27:13 2022 : Debug: Listening on acct proto tcp address * port 2018 bound to server passpoint Mon Sep 19 17:27:13 2022 : Debug: Listening on auth address * port 1817 bound to server passpoint Mon Sep 19 17:27:13 2022 : Debug: Listening on acct address * port 1818 bound to server passpoint Mon Sep 19 17:27:17 2022 : Debug: ... new connection request on TCP socket Mon Sep 19 17:27:17 2022 : Debug: Listening on acct from client (216.58.255.50, 42140) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:17 2022 : Debug: Waking up in 0.3 seconds. Mon Sep 19 17:27:17 2022 : Debug: Client has closed connection Mon Sep 19 17:27:17 2022 : Info: ... shutting down socket acct from client (216.58.255.50, 42140) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:17 2022 : Debug: Waking up in 2.9 seconds. Mon Sep 19 17:27:20 2022 : Debug: ... cleaning up socket acct from client (216.58.255.50, 42140) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:25 2022 : Debug: ... new connection request on TCP socket Mon Sep 19 17:27:25 2022 : Error: Failed inserting TCP socket into parent list. Mon Sep 19 17:27:25 2022 : Debug: Listening on acct from client (216.58.255.50, 37328) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:25 2022 : Debug: Waking up in 0.2 seconds. Mon Sep 19 17:27:25 2022 : Debug: Client has closed connection Mon Sep 19 17:27:25 2022 : Info: ... shutting down socket acct from client (216.58.255.50, 37328) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:25 2022 : Debug: Waking up in 2.9 seconds. Mon Sep 19 17:27:28 2022 : Debug: ... cleaning up socket acct from client (216.58.255.50, 37328) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:31 2022 : Debug: ... new connection request on TCP socket Mon Sep 19 17:27:31 2022 : Error: Failed inserting TCP socket into parent list. Mon Sep 19 17:27:31 2022 : Debug: Listening on acct from client (216.58.255.50, 54860) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:31 2022 : Debug: Waking up in 0.7 seconds. Mon Sep 19 17:27:31 2022 : Debug: Client has closed connection Mon Sep 19 17:27:31 2022 : Info: ... shutting down socket acct from client (216.58.255.50, 54860) -> (*, 2018, virtual-server=passpoint) Mon Sep 19 17:27:31 2022 : Debug: Waking up in 2.9 seconds. Mon Sep 19 17:27:34 2022 : Debug: ... cleaning up socket acct from client (216.58.255.50, 54860) -> (*, 2018, virtual-server=passpoint) Regards, Abhilash
On Sep 19, 2022, at 2:25 PM, Abhilash Y G <ygabhi@gmail.com> wrote:
I am configuring a virtual server to listen for authentication and accounting requests on TCP ports 2017 and 2018 respectively.
That should be fine.
When the request comes for the same host on 2018 (accounting port) I am seeing an error in radius log something like below. Please note all accounting messages are being successfully processed by virtual server.
Mon Sep 19 16:24:23 2022 : Error: Failed inserting TCP socket into parent list.
That's a little weird. I don't recall seeing that before.
Mon Sep 19 16:24:23 2022 : Info: ... adding new socket acct from client (20 8.59.110.70, 45060) -> (*, 2018) Mon Sep 19 16:24:23 2022 : Info: ... shutting down socket acct from client (208.59.110.70, 45060) -> (*, 2018)
freeradius logs in debug mode.
Mon Sep 19 17:27:08 2022 : Debug: Server was built with: Mon Sep 19 17:27:08 2022 : Debug: accounting : yes Mon Sep 19 17:27:08 2022 : Debug: authentication : yes
<sigh> Can people PLEASE follow the documentation for posting to the list? http://wiki.freeradius.org/list-help There are many, many, pieces of documentation which say what to post. There is simply no excuse to ignore all of the existing documentation. Use 3.2.0. It should work. Otherwise, source code is available. I suggest using a debugger. Alan DeKok.
participants (2)
-
Abhilash Y G -
Alan DeKok