Robust Proxy Accounting problem after switch from 2.2.10 to 3.2.1
Martin Zaharinov
micron10 at gmail.com
Wed Nov 23 16:50:55 UTC 2022
Hi Alan
on last line after stop radius with ctrl+ C i see this :
Last error was: Received Accounting-Response packet from home server 192.168.10.1 port 1813 with invalid Response Authenticator! (Shared secret is incorrect.)
but secret is set properly:
home_server home1.example.com {
type = acct
src_ipaddr = 10.10.10.1
ipaddr = 192.168.10.1
port = 1813
secret = “secret"
status_check = request
username = "test_bgbras"
response_window = 20
revive_interval = 120
check_interval = 30
num_answers_to_alive = 3
max_outstanding = 65536
zombie_period = 40
}
Below will see log from develop mode:
Wed Nov 23 22:08:31 2022 : Debug: Server was built with:
Wed Nov 23 22:08:31 2022 : Debug: accounting : yes
Wed Nov 23 22:08:31 2022 : Debug: authentication : yes
Wed Nov 23 22:08:31 2022 : Debug: ascend-binary-attributes : yes
Wed Nov 23 22:08:31 2022 : Debug: coa : yes
Wed Nov 23 22:08:31 2022 : Debug: recv-coa-from-home-server : yes
Wed Nov 23 22:08:31 2022 : Debug: control-socket : yes
Wed Nov 23 22:08:31 2022 : Debug: detail : yes
Wed Nov 23 22:08:31 2022 : Debug: dhcp : yes
Wed Nov 23 22:08:31 2022 : Debug: dynamic-clients : yes
Wed Nov 23 22:08:31 2022 : Debug: osfc2 : no
Wed Nov 23 22:08:31 2022 : Debug: proxy : yes
Wed Nov 23 22:08:31 2022 : Debug: regex-pcre : yes
Wed Nov 23 22:08:31 2022 : Debug: regex-posix : no
Wed Nov 23 22:08:31 2022 : Debug: regex-posix-extended : no
Wed Nov 23 22:08:31 2022 : Debug: session-management : yes
Wed Nov 23 22:08:31 2022 : Debug: stats : yes
Wed Nov 23 22:08:31 2022 : Debug: systemd : no
Wed Nov 23 22:08:31 2022 : Debug: tcp : yes
Wed Nov 23 22:08:31 2022 : Debug: threads : yes
Wed Nov 23 22:08:31 2022 : Debug: tls : yes
Wed Nov 23 22:08:31 2022 : Debug: unlang : yes
Wed Nov 23 22:08:31 2022 : Debug: vmps : yes
Wed Nov 23 22:08:31 2022 : Debug: developer : yes
Wed Nov 23 22:08:31 2022 : Debug: Server core libs:
Wed Nov 23 22:08:31 2022 : Debug: freeradius-server : 3.2.2
Wed Nov 23 22:08:31 2022 : Debug: talloc : 2.3.*
Wed Nov 23 22:08:31 2022 : Debug: ssl : 3.0.0g dev
Wed Nov 23 22:08:31 2022 : Debug: pcre : 8.45 2021-06-15
Wed Nov 23 22:08:31 2022 : Debug: Endianness:
Wed Nov 23 22:08:31 2022 : Debug: little
Wed Nov 23 22:08:31 2022 : Debug: Compilation flags:
Wed Nov 23 22:08:31 2022 : Debug: cppflags : -pipe -O3 -Wall -march=skylake -D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -D_FILE_OFFSET_BITS=64 -fno-stack-protector -mno-stackrealign -flto=4 -I/build/orionos/s64/include -I/build/orionos/s64/usr/include
Wed Nov 23 22:08:31 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 -pipe -O3 -Wall -march=skylake -D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -D_FILE_OFFSET_BITS=64 -fno-stack-protector -mno-stackrealign -flto=4 -I/build/orionos/s64/include -I/build/orionos/s64/usr/include -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -Wshadow -Wpointer-arith -Wcast-qual -Wcast-align -Wwrite-strings -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -Wnested-externs -W -Wredundant-decls -Wundef -Wformat-y2k -Wno-format-extra-args -Wno-format-zero-length -Wno-cast-align -Wformat-nonliteral -Wformat-security -Wformat=2 -DWITH_VERIFY_PTR=1 -DIS_MODULE=1
Wed Nov 23 22:08:31 2022 : Debug: ldflags : -L/build/orionos/s64/lib -L/build/orionos/s64/usr/lib
Wed Nov 23 22:08:31 2022 : Debug: libs : -lcrypto -lssl -ltalloc -latomic -lpcre -lcap -lresolv -ldl -lpthread -lz -lmariadb -lp11-kit -lhogweed -lgmp -lidn -lidn2 -lffi -lgnutls -lnettle -lmysqlclient -lreadline -lssl -lcrypto -lncurses -ltinfo -lltdl -liconv -lexpat -lpcre -lbz2 -llzma -lxml2 -lnl-3 -lnl-genl-3 -lnl-route-3 -ltinfo -ltirpc -lssl -lcrypto -lboost_regex -lboost_serialization -lboost_wserialization -lboost_system -lcap -lpcap -lreadline
Wed Nov 23 22:08:31 2022 : Debug:
Wed Nov 23 22:08:31 2022 : Info: FreeRADIUS Version 3.2.2
Wed Nov 23 22:08:31 2022 : Info: Copyright (C) 1999-2022 The FreeRADIUS server project and contributors
Wed Nov 23 22:08:31 2022 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Wed Nov 23 22:08:31 2022 : Info: PARTICULAR PURPOSE
Wed Nov 23 22:08:31 2022 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Wed Nov 23 22:08:31 2022 : Info: GNU General Public License
Wed Nov 23 22:08:31 2022 : Info: For more information about these matters, see the file named COPYRIGHT
Wed Nov 23 22:08:31 2022 : Info: Starting - reading configuration files ...
Wed Nov 23 22:08:31 2022 : Debug: including dictionary file /etc/freeradius/dictionary
Wed Nov 23 22:08:31 2022 : Debug: including dictionary file /etc/freeradius/dictionary
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/freeradius.conf
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/proxy.conf
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/clients.conf
Wed Nov 23 22:08:31 2022 : Debug: including files in directory /etc/freeradius/policy.d/
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/policy.d/accounting
Wed Nov 23 22:08:31 2022 : Debug: including files in directory /etc/freeradius/modules/
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/expr
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/exec
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/chap
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/pap
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/detail
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/detail.example.com
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/modules/preprocess
Wed Nov 23 22:08:31 2022 : Debug: including files in directory /etc/freeradius/sites-enabled/
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:08:31 2022 : Debug: including configuration file /etc/freeradius/sites-enabled/default
Wed Nov 23 22:08:31 2022 : Debug: main {
Wed Nov 23 22:08:31 2022 : Debug: security {
Wed Nov 23 22:08:31 2022 : Debug: user = "freerad"
Wed Nov 23 22:08:31 2022 : Debug: group = "freerad"
Wed Nov 23 22:08:31 2022 : Debug: allow_core_dumps = no
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[38]: The item 'max_attributes' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[39]: The item 'reject_delay' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[40]: The item 'status_server' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[41]: The item 'allow_vulnerable_openssl' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: name = "radiusd"
Wed Nov 23 22:08:31 2022 : Debug: prefix = "/usr"
Wed Nov 23 22:08:31 2022 : Debug: localstatedir = "/var"
Wed Nov 23 22:08:31 2022 : Debug: logdir = "/var/log/freeradius"
Wed Nov 23 22:08:31 2022 : Debug: run_dir = "/var/run/freeradius"
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[2]: The item 'ignore_case' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[4]: The item 'sysconfdir' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[9]: The item 'log_file' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[10]: The item 'log_destination' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[12]: The item 'confdir' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[14]: The item 'libdir' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[15]: The item 'pidfile' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[16]: The item 'max_request_time' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[17]: The item 'cleanup_delay' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[18]: The item 'max_requests' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[29]: The item 'hostname_lookups' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[30]: The item 'regular_expressions' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[31]: The item 'extended_expressions' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[32]: The item 'checkrad' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[44]: The item 'proxy_requests' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: main {
Wed Nov 23 22:08:31 2022 : Debug: name = "radiusd"
Wed Nov 23 22:08:31 2022 : Debug: prefix = "/usr"
Wed Nov 23 22:08:31 2022 : Debug: localstatedir = "/var"
Wed Nov 23 22:08:31 2022 : Debug: sbindir = "/usr/sbin"
Wed Nov 23 22:08:31 2022 : Debug: logdir = "/var/log/freeradius"
Wed Nov 23 22:08:31 2022 : Debug: run_dir = "/var/run/freeradius"
Wed Nov 23 22:08:31 2022 : Debug: libdir = "/usr/lib/freeradius"
Wed Nov 23 22:08:31 2022 : Debug: radacctdir = "/var/log/freeradius/radacct"
Wed Nov 23 22:08:31 2022 : Debug: hostname_lookups = no
Wed Nov 23 22:08:31 2022 : Debug: max_request_time = 30
Wed Nov 23 22:08:31 2022 : Debug: cleanup_delay = 5
Wed Nov 23 22:08:31 2022 : Debug: max_requests = 1024
Wed Nov 23 22:08:31 2022 : Debug: postauth_client_lost = no
Wed Nov 23 22:08:31 2022 : Debug: pidfile = "/var/run/freeradius/freeradius.pid"
Wed Nov 23 22:08:31 2022 : Debug: checkrad = "/usr/sbin/checkrad"
Wed Nov 23 22:08:31 2022 : Debug: debug_level = 0
Wed Nov 23 22:08:31 2022 : Debug: proxy_requests = yes
Wed Nov 23 22:08:31 2022 : Debug: log {
Wed Nov 23 22:08:31 2022 : Debug: stripped_names = no
Wed Nov 23 22:08:31 2022 : Debug: auth = no
Wed Nov 23 22:08:31 2022 : Debug: auth_badpass = no
Wed Nov 23 22:08:31 2022 : Debug: auth_goodpass = no
Wed Nov 23 22:08:31 2022 : Debug: msg_denied = "You are already logged in - access denied"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: resources {
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: security {
Wed Nov 23 22:08:31 2022 : Debug: max_attributes = 200
Wed Nov 23 22:08:31 2022 : Debug: reject_delay = 1.000000
Wed Nov 23 22:08:31 2022 : Debug: status_server = yes
Wed Nov 23 22:08:31 2022 : Debug: allow_vulnerable_openssl = "no"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[2]: The item 'ignore_case' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[4]: The item 'sysconfdir' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[9]: The item 'log_file' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[10]: The item 'log_destination' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[12]: The item 'confdir' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[30]: The item 'regular_expressions' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/freeradius.conf[31]: The item 'extended_expressions' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: freeradius: #### Loading Realms and Home Servers ####
Wed Nov 23 22:08:31 2022 : Debug: proxy server {
Wed Nov 23 22:08:31 2022 : Debug: retry_delay = 5
Wed Nov 23 22:08:31 2022 : Debug: retry_count = 3
Wed Nov 23 22:08:31 2022 : Debug: default_fallback = yes
Wed Nov 23 22:08:31 2022 : Debug: dead_time = 120
Wed Nov 23 22:08:31 2022 : Debug: wake_all_if_all_dead = no
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/proxy.conf[2]: The item 'synchronous' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/proxy.conf[7]: The item 'post_proxy_authorize' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: home_server home1.example.com {
Wed Nov 23 22:08:31 2022 : Debug: nonblock = no
Wed Nov 23 22:08:31 2022 : Debug: ipaddr = 192.168.10.1
Wed Nov 23 22:08:31 2022 : Debug: port = 1813
Wed Nov 23 22:08:31 2022 : Debug: type = "acct"
Wed Nov 23 22:08:31 2022 : Debug: secret = "secret"
Wed Nov 23 22:08:31 2022 : Debug: src_ipaddr = "10.10.10.1"
Wed Nov 23 22:08:31 2022 : Debug: response_window = 6.000000
Wed Nov 23 22:08:31 2022 : Debug: response_timeouts = 1
Wed Nov 23 22:08:31 2022 : Debug: max_outstanding = 65536
Wed Nov 23 22:08:31 2022 : Debug: zombie_period = 40
Wed Nov 23 22:08:31 2022 : Debug: status_check = "request"
Wed Nov 23 22:08:31 2022 : Debug: ping_interval = 30
Wed Nov 23 22:08:31 2022 : Debug: check_timeout = 4
Wed Nov 23 22:08:31 2022 : Debug: num_answers_to_alive = 3
Wed Nov 23 22:08:31 2022 : Debug: revive_interval = 300
Wed Nov 23 22:08:31 2022 : Debug: username = "test_user_status_check"
Wed Nov 23 22:08:31 2022 : Debug: limit {
Wed Nov 23 22:08:31 2022 : Debug: max_connections = 16
Wed Nov 23 22:08:31 2022 : Debug: max_requests = 0
Wed Nov 23 22:08:31 2022 : Debug: lifetime = 0
Wed Nov 23 22:08:31 2022 : Debug: idle_timeout = 0
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: coa {
Wed Nov 23 22:08:31 2022 : Debug: irt = 2
Wed Nov 23 22:08:31 2022 : Debug: mrt = 16
Wed Nov 23 22:08:31 2022 : Debug: mrc = 5
Wed Nov 23 22:08:31 2022 : Debug: mrd = 30
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: recv_coa {
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: realm LOCAL {
Wed Nov 23 22:08:31 2022 : Debug: authhost = LOCAL
Wed Nov 23 22:08:31 2022 : Debug: accthost = LOCAL
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: home_server_pool acct_pool.example.com {
Wed Nov 23 22:08:31 2022 : Debug: type = load-balance
Wed Nov 23 22:08:31 2022 : Debug: virtual_server = home.example.com
Wed Nov 23 22:08:31 2022 : Debug: home_server = home1.example.com
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: realm acct_realm.example.com {
Wed Nov 23 22:08:31 2022 : Debug: acct_pool = acct_pool.example.com
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: freeradius: #### Loading Clients ####
Wed Nov 23 22:08:31 2022 : Debug: client 127.0.0.1 {
Wed Nov 23 22:08:31 2022 : Debug: ipaddr = 10.10.10.1
Wed Nov 23 22:08:31 2022 : Debug: require_message_authenticator = no
Wed Nov 23 22:08:31 2022 : Debug: secret = "secret"
Wed Nov 23 22:08:31 2022 : Debug: limit {
Wed Nov 23 22:08:31 2022 : Debug: max_connections = 16
Wed Nov 23 22:08:31 2022 : Debug: lifetime = 0
Wed Nov 23 22:08:31 2022 : Debug: idle_timeout = 30
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Adding client 10.10.10.1/32 (10.10.10.1) to prefix tree 32
Wed Nov 23 22:08:31 2022 : Info: Debugger not attached
Wed Nov 23 22:08:31 2022 : Debug: freeradius: #### Instantiating modules ####
Wed Nov 23 22:08:31 2022 : Debug: modules {
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_expr with path: /usr/lib/freeradius/rlm_expr.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_expr, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_expr
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "expr" from file /etc/freeradius/modules/expr
Wed Nov 23 22:08:31 2022 : Debug: expr {
Wed Nov 23 22:08:31 2022 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_exec with path: /usr/lib/freeradius/rlm_exec.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_exec, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_exec
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "exec" from file /etc/freeradius/modules/exec
Wed Nov 23 22:08:31 2022 : Debug: exec {
Wed Nov 23 22:08:31 2022 : Debug: wait = no
Wed Nov 23 22:08:31 2022 : Debug: input_pairs = "request"
Wed Nov 23 22:08:31 2022 : Debug: shell_escape = yes
Wed Nov 23 22:08:31 2022 : Debug: timeout = 10
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/modules/exec[28]: The item 'output' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_chap with path: /usr/lib/freeradius/rlm_chap.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_chap, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_chap
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "chap" from file /etc/freeradius/modules/chap
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_pap with path: /usr/lib/freeradius/rlm_pap.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_pap, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_pap
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "pap" from file /etc/freeradius/modules/pap
Wed Nov 23 22:08:31 2022 : Debug: pap {
Wed Nov 23 22:08:31 2022 : Debug: normalise = yes
Wed Nov 23 22:08:31 2022 : Warning: /etc/freeradius/modules/pap[21]: The item 'auto_header' is defined, but is unused by the configuration
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_detail with path: /usr/lib/freeradius/rlm_detail.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_detail, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_detail
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "detail" from file /etc/freeradius/modules/detail
Wed Nov 23 22:08:31 2022 : Debug: detail {
Wed Nov 23 22:08:31 2022 : Debug: filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Wed Nov 23 22:08:31 2022 : Debug: header = "%t"
Wed Nov 23 22:08:31 2022 : Debug: permissions = 384
Wed Nov 23 22:08:31 2022 : Debug: locking = no
Wed Nov 23 22:08:31 2022 : Debug: escape_filenames = no
Wed Nov 23 22:08:31 2022 : Debug: log_packet_header = no
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "detail.example.com" from file /etc/freeradius/modules/detail.example.com
Wed Nov 23 22:08:31 2022 : Debug: detail detail.example.com {
Wed Nov 23 22:08:31 2022 : Debug: filename = "/var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G"
Wed Nov 23 22:08:31 2022 : Debug: header = "%t"
Wed Nov 23 22:08:31 2022 : Debug: permissions = 384
Wed Nov 23 22:08:31 2022 : Debug: locking = no
Wed Nov 23 22:08:31 2022 : Debug: escape_filenames = no
Wed Nov 23 22:08:31 2022 : Debug: log_packet_header = no
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Loading rlm_preprocess with path: /usr/lib/freeradius/rlm_preprocess.so
Wed Nov 23 22:08:31 2022 : Debug: Loaded rlm_preprocess, checking if it's valid
Wed Nov 23 22:08:31 2022 : Debug: # Loaded module rlm_preprocess
Wed Nov 23 22:08:31 2022 : Debug: # Loading module "preprocess" from file /etc/freeradius/modules/preprocess
Wed Nov 23 22:08:31 2022 : Debug: preprocess {
Wed Nov 23 22:08:31 2022 : Debug: huntgroups = "/etc/freeradius/huntgroups"
Wed Nov 23 22:08:31 2022 : Debug: hints = "/etc/freeradius/hints"
Wed Nov 23 22:08:31 2022 : Debug: with_ascend_hack = no
Wed Nov 23 22:08:31 2022 : Debug: ascend_channels_per_line = 23
Wed Nov 23 22:08:31 2022 : Debug: with_ntdomain_hack = no
Wed Nov 23 22:08:31 2022 : Debug: with_specialix_jetstream_hack = no
Wed Nov 23 22:08:31 2022 : Debug: with_cisco_vsa_hack = no
Wed Nov 23 22:08:31 2022 : Debug: with_alvarion_vsa_hack = no
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: instantiate {
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: # Instantiating module "pap" from file /etc/freeradius/modules/pap
Wed Nov 23 22:08:31 2022 : Debug: # Instantiating module "detail" from file /etc/freeradius/modules/detail
Wed Nov 23 22:08:31 2022 : Debug: # Instantiating module "detail.example.com" from file /etc/freeradius/modules/detail.example.com
Wed Nov 23 22:08:31 2022 : Debug: # Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess
Wed Nov 23 22:08:31 2022 : Debug: reading pairlist file /etc/freeradius/huntgroups
Wed Nov 23 22:08:31 2022 : Debug: reading pairlist file /etc/freeradius/hints
Wed Nov 23 22:08:31 2022 : Debug: } # modules
Wed Nov 23 22:08:31 2022 : Debug: freeradius: #### Loading Virtual Servers ####
Wed Nov 23 22:08:31 2022 : Debug: server { # from file /etc/freeradius/freeradius.conf
Wed Nov 23 22:08:31 2022 : Error: /etc/freeradius/sites-enabled/default[1]: The authorize section should be inside of a 'server { ... }' block!
Wed Nov 23 22:08:31 2022 : Debug: authorize {
Wed Nov 23 22:08:31 2022 : Debug: preprocess
Wed Nov 23 22:08:31 2022 : Debug: chap
Wed Nov 23 22:08:31 2022 : Debug: pap
Wed Nov 23 22:08:31 2022 : Debug: } # authorize
Wed Nov 23 22:08:31 2022 : Error: /etc/freeradius/sites-enabled/default[18]: The preacct section should be inside of a 'server { ... }' block!
Wed Nov 23 22:08:31 2022 : Debug: preacct {
Wed Nov 23 22:08:31 2022 : Debug: preprocess
Wed Nov 23 22:08:31 2022 : Debug: policy acct_unique {
Wed Nov 23 22:08:31 2022 : Debug: update {
Wed Nov 23 22:08:31 2022 : Debug: &Tmp-String-9 := "ai:"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) {
Wed Nov 23 22:08:31 2022 : Debug: update {
Wed Nov 23 22:08:31 2022 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: else {
Wed Nov 23 22:08:31 2022 : Debug: update {
Wed Nov 23 22:08:31 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}}"
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: update {
Wed Nov 23 22:08:31 2022 : Debug: &Tmp-String-9 !* ANY
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: } # preacct
Wed Nov 23 22:08:31 2022 : Error: /etc/freeradius/sites-enabled/default[23]: The accounting section should be inside of a 'server { ... }' block!
Wed Nov 23 22:08:31 2022 : Debug: accounting {
Wed Nov 23 22:08:31 2022 : Debug: detail
Wed Nov 23 22:08:31 2022 : Debug: detail.example.com
Wed Nov 23 22:08:31 2022 : Debug: } # accounting
Wed Nov 23 22:08:31 2022 : Debug: } # server
Wed Nov 23 22:08:31 2022 : Debug: server home.example.com { # from file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:08:31 2022 : Debug: accounting {
Wed Nov 23 22:08:31 2022 : Debug: update {
Wed Nov 23 22:08:31 2022 : Debug: &control:Proxy-To-Realm := 'acct_realm.example.com'
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: } # accounting
Wed Nov 23 22:08:31 2022 : Debug: post-proxy {
Wed Nov 23 22:08:31 2022 : Debug: Compiling Post-Proxy-Type Fail-Accounting for attr Post-Proxy-Type
Wed Nov 23 22:08:31 2022 : Debug: group {
Wed Nov 23 22:08:31 2022 : Debug: detail.example.com
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Compiling Post-Proxy-Type Fail-Authentication for attr Post-Proxy-Type
Wed Nov 23 22:08:31 2022 : Debug: group {
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: } # post-proxy
Wed Nov 23 22:08:31 2022 : Debug: } # server home.example.com
Wed Nov 23 22:08:31 2022 : Debug: Created signal pipe. Read end FD 5, write end FD 6
Wed Nov 23 22:08:31 2022 : Debug: freeradius: #### Opening IP addresses and Ports ####
Wed Nov 23 22:08:31 2022 : Debug: Loading proto_acct with path: /usr/lib/freeradius/proto_acct.so
Wed Nov 23 22:08:31 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
Wed Nov 23 22:08:31 2022 : Debug: Loading library using linker search path(s)
Wed Nov 23 22:08:31 2022 : Debug: Defaults : /lib:/usr/lib
Wed Nov 23 22:08:31 2022 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory
Wed Nov 23 22:08:31 2022 : Debug: listen {
Wed Nov 23 22:08:31 2022 : Debug: type = "acct"
Wed Nov 23 22:08:31 2022 : Debug: ipaddr = *
Wed Nov 23 22:08:31 2022 : Debug: port = 0
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Loading proto_detail with path: /usr/lib/freeradius/proto_detail.so
Wed Nov 23 22:08:31 2022 : Debug: Loading proto_detail failed: /usr/lib/freeradius/proto_detail.so: cannot open shared object file: No such file or directory - No such file or directory
Wed Nov 23 22:08:31 2022 : Debug: Loading library using linker search path(s)
Wed Nov 23 22:08:31 2022 : Debug: Defaults : /lib:/usr/lib
Wed Nov 23 22:08:31 2022 : Debug: Failed with error: proto_detail.so: cannot open shared object file: No such file or directory
Wed Nov 23 22:08:31 2022 : Debug: listen {
Wed Nov 23 22:08:31 2022 : Debug: type = "detail"
Wed Nov 23 22:08:31 2022 : Debug: listen {
Wed Nov 23 22:08:31 2022 : Debug: filename = "/var/log/freeradius/radacct/detail.example.com/detail-*:*"
Wed Nov 23 22:08:31 2022 : Debug: load_factor = 10
Wed Nov 23 22:08:31 2022 : Debug: poll_interval = 1
Wed Nov 23 22:08:31 2022 : Debug: retry_interval = 30
Wed Nov 23 22:08:31 2022 : Debug: one_shot = no
Wed Nov 23 22:08:31 2022 : Debug: track = no
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: }
Wed Nov 23 22:08:31 2022 : Debug: Listening on acct address * port 1813
Wed Nov 23 22:08:31 2022 : Debug: Listening on detail file /var/log/freeradius/radacct/detail.example.com/detail-*:* as server home.example.com
Wed Nov 23 22:08:31 2022 : Info: Ready to process requests
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - User-Name = "test_bgbras"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - NAS-Identifier = "demo-bng"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - NAS-IP-Address = 10.10.10.1
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - NAS-Port = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - NAS-Port-Id = "vlan100"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - NAS-Port-Type = Virtual
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Service-Type = Framed-User
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Framed-Protocol = PPP
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Calling-Station-Id = "f6:cb:f6:40:1f:a0"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Called-Station-Id = "1a:27:b5:27:bb:53"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Class = 0x6375693d746573745f6267627261732c73753d3934323033392c736b3d726a70366a6f656e667561682c626b69643d32323534303038392c626b7269643d332c6d763d3532393135313830303939372c6d743d3630343831352c676d743d3630343830302c73703d312c73723d2c61633d312c75693d3934323033392c6363693d3138382c63633d47656e6572616c2c61733d312c636f3d2c64623d3130323430302c75623d3130323430302c63626b69643d3232353430303930
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Status-Type = Start
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Authentic = RADIUS
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Session-Id = "4e48d224df6f0c10"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Session-Time = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Input-Octets = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Output-Octets = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Input-Packets = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Output-Packets = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Input-Gigawords = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Output-Gigawords = 0
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Framed-IP-Address = 10.0.0.1
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Event-Timestamp = "Nov 23 2022 22:06:45 IST"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Trying to read VP from line - Acct-Unique-Session-Id = "994228513543d72dc0dd509c7ce37743"
Wed Nov 23 22:08:31 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Read packet from /var/log/freeradius/radacct/detail.example.com/detail.work
User-Name = "test_bgbras"
NAS-Identifier = "demo-bng"
NAS-IP-Address = 10.10.10.1
NAS-Port = 0
NAS-Port-Id = "vlan100"
NAS-Port-Type = Virtual
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "f6:cb:f6:40:1f:a0"
Called-Station-Id = "1a:27:b5:27:bb:53"
Class = 0x6375693d746573745f6267627261732c73753d3934323033392c736b3d726a70366a6f656e667561682c626b69643d32323534303038392c626b7269643d332c6d763d3532393135313830303939372c6d743d3630343831352c676d743d3630343830302c73703d312c73723d2c61633d312c75693d3934323033392c6363693d3138382c63633d47656e6572616c2c61733d312c636f3d2c64623d3130323430302c75623d3130323430302c63626b69643d3232353430303930
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Acct-Session-Id = "4e48d224df6f0c10"
Acct-Session-Time = 0
Acct-Input-Octets = 0
Acct-Output-Octets = 0
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Framed-IP-Address = 10.0.0.1
Event-Timestamp = "Nov 23 2022 22:06:45 IST"
Acct-Unique-Session-Id = "994228513543d72dc0dd509c7ce37743"
Packet-Original-Timestamp = "Nov 23 2022 22:06:45 IST"
Acct-Delay-Time = 106
Packet-Transmit-Counter = 1
Wed Nov 23 22:08:31 2022 : Debug: (0) Empty preacct section in virtual server "home.example.com". Using default return values.
Wed Nov 23 22:08:31 2022 : Debug: (0) # Executing section accounting from file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:08:31 2022 : Debug: (0) accounting {
Wed Nov 23 22:08:31 2022 : Debug: (0) update control {
Wed Nov 23 22:08:31 2022 : Debug: (0) &Proxy-To-Realm := 'acct_realm.example.com'
Wed Nov 23 22:08:31 2022 : Debug: (0) } # update control = noop
Wed Nov 23 22:08:31 2022 : Debug: (0) } # accounting = noop
Wed Nov 23 22:08:31 2022 : Debug: Using home pool acct for realm acct_realm.example.com
Wed Nov 23 22:08:31 2022 : Debug: (0) Starting proxy to home server 192.168.10.1 port 1813
Wed Nov 23 22:08:31 2022 : Debug: (0) server home.example.com {
Wed Nov 23 22:08:31 2022 : Debug: (0) Empty pre-proxy section in virtual server "home.example.com". Using default return values.
Wed Nov 23 22:08:31 2022 : Debug: (0) }
Wed Nov 23 22:08:31 2022 : Debug: (0) proxy: Trying to allocate ID (0/2)
Wed Nov 23 22:08:31 2022 : Debug: (0) proxy: Trying to open a new listener to the home server
Wed Nov 23 22:08:31 2022 : Debug: Opened new proxy socket 'proxy address 10.10.10.1 port 38663'
Wed Nov 23 22:08:31 2022 : Debug: Listening on proxy address 10.10.10.1 port 38663
Wed Nov 23 22:08:31 2022 : Debug: (0) proxy: Trying to allocate ID (1/2)
Wed Nov 23 22:08:31 2022 : Debug: (0) proxy: request is now in proxy hash
Wed Nov 23 22:08:31 2022 : Debug: (0) proxy: allocating destination 192.168.10.1 port 1813 - Id 176
Wed Nov 23 22:08:31 2022 : Debug: (0) Proxying request to home server 192.168.10.1 port 1813 timeout 6.000000
01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 6a
21 03 30
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 176
Length: 402
Vector: 00000000000000000000000000000000
Data: 01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 6a
21 03 30
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 176
Length: 402
Vector: b37fbdebc7cc8eb12816dcd2329e9053
Data: 01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 6a
21 03 30
Wed Nov 23 22:08:31 2022 : Debug: Waking up in 0.3 seconds.
Socket: 13
Proto: 0
Src IP: 192.168.10.1
port: 1813
Dst IP: 10.10.10.1
port: 38663
Code: (5) Accounting-Response
Id: 176
Length: 20
Vector: f78be0bb643267411026c59d02ad7669
Wed Nov 23 22:08:31 2022 : Debug: Ignoring spoofed proxy reply. Signature is invalid
Wed Nov 23 22:08:31 2022 : Debug: Waking up in 0.1 seconds.
Wed Nov 23 22:08:31 2022 : Debug: (0) Expecting proxy response no later than 5.666579 seconds from now
Wed Nov 23 22:08:31 2022 : Debug: Waking up in 5.6 seconds.
Wed Nov 23 22:08:37 2022 : Debug: (0) No proxy response, giving up on request and marking it done
Wed Nov 23 22:08:37 2022 : Proxy: Marking home server 192.168.10.1 port 1813 as zombie (it has not responded in 6.000000 seconds).
Wed Nov 23 22:08:37 2022 : Debug: (1) proxy: Trying to allocate ID (0/2)
Wed Nov 23 22:08:37 2022 : Debug: (1) proxy: request is now in proxy hash
Wed Nov 23 22:08:37 2022 : Debug: (1) proxy: allocating destination 192.168.10.1 port 1813 - Id 44
Wed Nov 23 22:08:37 2022 : Debug: PING: Waiting 4 seconds for response to ping
01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c 8d
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 30 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 44
Length: 98
Vector: 00000000000000000000000000000000
Data: 01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c 8d
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 30 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Wed Nov 23 22:08:37 2022 : Debug: (1) Sent Accounting-Request Id 44 from 10.10.10.1:38663 to 192.168.10.1:1813 length 98
Wed Nov 23 22:08:37 2022 : Debug: (1) User-Name := "test_user_status_check"
Wed Nov 23 22:08:37 2022 : Debug: (1) Acct-Status-Type := Stop
Wed Nov 23 22:08:37 2022 : Debug: (1) Acct-Session-Id := "00000000"
Wed Nov 23 22:08:37 2022 : Debug: (1) Event-Timestamp := "Nov 23 2022 22:08:37 IST"
Wed Nov 23 22:08:37 2022 : Debug: (1) NAS-Identifier := "Status Check 0. Are you alive?"
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 44
Length: 98
Vector: 83bff5db562147bbbf4f22bf060e6ccd
Data: 01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c 8d
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 30 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Wed Nov 23 22:08:37 2022 : Debug: PING: Next status packet in 30 seconds
Wed Nov 23 22:08:37 2022 : ERROR: (0) Failing proxied request for user "test_bgbras", due to lack of any response from home server 192.168.10.1 port 1813
Wed Nov 23 22:08:37 2022 : Debug: (0) Clearing existing &reply: attributes
Wed Nov 23 22:08:37 2022 : Debug: (0) Found Post-Proxy-Type Fail-Accounting
Wed Nov 23 22:08:37 2022 : Debug: (0) server home.example.com {
Wed Nov 23 22:08:37 2022 : Debug: (0) # Executing group from file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:08:37 2022 : Debug: (0) Post-Proxy-Type Fail-Accounting {
Wed Nov 23 22:08:37 2022 : Debug: (0) modsingle[post-proxy]: calling detail.example.com (rlm_detail)
Wed Nov 23 22:08:37 2022 : Debug: /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G
Wed Nov 23 22:08:37 2022 : Debug: Parsed xlat tree:
Wed Nov 23 22:08:37 2022 : Debug: literal --> /var/log/freeradius/radacct/detail.example.com/detail-
Wed Nov 23 22:08:37 2022 : Debug: percent --> Y
Wed Nov 23 22:08:37 2022 : Debug: percent --> m
Wed Nov 23 22:08:37 2022 : Debug: percent --> d
Wed Nov 23 22:08:37 2022 : Debug: literal --> :
Wed Nov 23 22:08:37 2022 : Debug: percent --> H
Wed Nov 23 22:08:37 2022 : Debug: literal --> :
Wed Nov 23 22:08:37 2022 : Debug: percent --> G
Wed Nov 23 22:08:37 2022 : Debug: (0) detail.example.com: EXPAND /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G
Wed Nov 23 22:08:37 2022 : Debug: (0) detail.example.com: --> /var/log/freeradius/radacct/detail.example.com/detail-20221123:22:08
Wed Nov 23 22:08:37 2022 : Debug: (0) detail.example.com: /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G expands to /var/log/freeradius/radacct/detail.example.com/detail-20221123:22:08
Wed Nov 23 22:08:37 2022 : WARNING: (0) detail.example.com: Suppressing infinite loop
Wed Nov 23 22:08:37 2022 : Debug: (0) modsingle[post-proxy]: returned from detail.example.com (rlm_detail)
Wed Nov 23 22:08:37 2022 : Debug: (0) [detail.example.com] = noop
Wed Nov 23 22:08:37 2022 : Debug: (0) } # Post-Proxy-Type Fail-Accounting = noop
Wed Nov 23 22:08:37 2022 : Debug: (0) }
Wed Nov 23 22:08:37 2022 : Debug: (0) detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): No response to request. Will retry in 30 seconds
Wed Nov 23 22:08:37 2022 : Debug: (0) Finished request
Wed Nov 23 22:08:37 2022 : Debug: (0) Cleaning up request packet ID 0 with timestamp +0 due to done
Wed Nov 23 22:08:37 2022 : Debug: Waking up in 3.9 seconds.
Socket: 13
Proto: 0
Src IP: 192.168.10.1
port: 1813
Dst IP: 10.10.10.1
port: 38663
Code: (5) Accounting-Response
Id: 44
Length: 20
Vector: de2b86fec5cb20c27752769f539136ee
Wed Nov 23 22:08:37 2022 : Debug: Ignoring spoofed proxy reply. Signature is invalid
Wed Nov 23 22:08:37 2022 : Debug: Waking up in 3.8 seconds.
Wed Nov 23 22:08:41 2022 : Error: No response to status check 1 ID 44 for home server 192.168.10.1 port 1813
Wed Nov 23 22:08:41 2022 : Debug: Waking up in 24.0 seconds.
Wed Nov 23 22:09:05 2022 : Debug: (2) proxy: Trying to allocate ID (0/2)
Wed Nov 23 22:09:05 2022 : Debug: (2) proxy: request is now in proxy hash
Wed Nov 23 22:09:05 2022 : Debug: (2) proxy: allocating destination 192.168.10.1 port 1813 - Id 131
Wed Nov 23 22:09:05 2022 : Debug: PING: Waiting 4 seconds for response to ping
01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c a9
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 31 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 131
Length: 98
Vector: 00000000000000000000000000000000
Data: 01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c a9
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 31 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Wed Nov 23 22:09:05 2022 : Debug: (2) Sent Accounting-Request Id 131 from 10.10.10.1:38663 to 192.168.10.1:1813 length 98
Wed Nov 23 22:09:05 2022 : Debug: (2) User-Name := "test_user_status_check"
Wed Nov 23 22:09:05 2022 : Debug: (2) Acct-Status-Type := Stop
Wed Nov 23 22:09:05 2022 : Debug: (2) Acct-Session-Id := "00000000"
Wed Nov 23 22:09:05 2022 : Debug: (2) Event-Timestamp := "Nov 23 2022 22:09:05 IST"
Wed Nov 23 22:09:05 2022 : Debug: (2) NAS-Identifier := "Status Check 1. Are you alive?"
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 131
Length: 98
Vector: 7d768f15d70c03c356df8a12e8dfa48b
Data: 01 18 74 65 73 74 5f 75 73 65 72 5f 73 74 61 74 75 73
5f 63 68 65 63 6b
28 06 00 00 00 02
2c 0a 30 30 30 30 30 30 30 30
37 06 63 7e 4c a9
20 20 53 74 61 74 75 73 20 43 68 65 63 6b 20 31 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Wed Nov 23 22:09:05 2022 : Debug: PING: Next status packet in 30 seconds
Wed Nov 23 22:09:05 2022 : Debug: Waking up in 3.9 seconds.
Socket: 13
Proto: 0
Src IP: 192.168.10.1
port: 1813
Dst IP: 10.10.10.1
port: 38663
Code: (5) Accounting-Response
Id: 131
Length: 20
Vector: 624cadfb5af94fde2dcb29058e2d891a
Wed Nov 23 22:09:05 2022 : Debug: Ignoring spoofed proxy reply. Signature is invalid
Wed Nov 23 22:09:05 2022 : Debug: Waking up in 3.8 seconds.
Wed Nov 23 22:09:07 2022 : Debug: detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): Read packet from /var/log/freeradius/radacct/detail.example.com/detail.work
User-Name = "test_bgbras"
NAS-Identifier = "demo-bng"
NAS-IP-Address = 10.10.10.1
NAS-Port = 0
NAS-Port-Id = "vlan100"
NAS-Port-Type = Virtual
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "f6:cb:f6:40:1f:a0"
Called-Station-Id = "1a:27:b5:27:bb:53"
Class = 0x6375693d746573745f6267627261732c73753d3934323033392c736b3d726a70366a6f656e667561682c626b69643d32323534303038392c626b7269643d332c6d763d3532393135313830303939372c6d743d3630343831352c676d743d3630343830302c73703d312c73723d2c61633d312c75693d3934323033392c6363693d3138382c63633d47656e6572616c2c61733d312c636f3d2c64623d3130323430302c75623d3130323430302c63626b69643d3232353430303930
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Acct-Session-Id = "4e48d224df6f0c10"
Acct-Session-Time = 0
Acct-Input-Octets = 0
Acct-Output-Octets = 0
Acct-Input-Packets = 0
Acct-Output-Packets = 0
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Framed-IP-Address = 10.0.0.1
Event-Timestamp = "Nov 23 2022 22:06:45 IST"
Acct-Unique-Session-Id = "994228513543d72dc0dd509c7ce37743"
Packet-Original-Timestamp = "Nov 23 2022 22:06:45 IST"
Acct-Delay-Time = 142
Packet-Transmit-Counter = 2
Wed Nov 23 22:09:07 2022 : Debug: (3) Empty preacct section in virtual server "home.example.com". Using default return values.
Wed Nov 23 22:09:07 2022 : Debug: (3) # Executing section accounting from file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:09:07 2022 : Debug: (3) accounting {
Wed Nov 23 22:09:07 2022 : Debug: (3) update control {
Wed Nov 23 22:09:07 2022 : Debug: (3) &Proxy-To-Realm := 'acct_realm.example.com'
Wed Nov 23 22:09:07 2022 : Debug: (3) } # update control = noop
Wed Nov 23 22:09:07 2022 : Debug: (3) } # accounting = noop
Wed Nov 23 22:09:07 2022 : Debug: Using home pool acct for realm acct_realm.example.com
Wed Nov 23 22:09:07 2022 : Debug: (3) Starting proxy to home server 192.168.10.1 port 1813
Wed Nov 23 22:09:07 2022 : Debug: (3) server home.example.com {
Wed Nov 23 22:09:07 2022 : Debug: (3) Empty pre-proxy section in virtual server "home.example.com". Using default return values.
Wed Nov 23 22:09:07 2022 : Debug: (3) }
Wed Nov 23 22:09:07 2022 : Debug: (3) proxy: Trying to allocate ID (0/2)
Wed Nov 23 22:09:07 2022 : Debug: (3) proxy: request is now in proxy hash
Wed Nov 23 22:09:07 2022 : Debug: (3) proxy: allocating destination 192.168.10.1 port 1813 - Id 228
Wed Nov 23 22:09:07 2022 : Debug: (3) Proxying request to home server 192.168.10.1 port 1813 timeout 6.000000
01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 8e
21 03 30
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 228
Length: 402
Vector: 00000000000000000000000000000000
Data: 01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 8e
21 03 30
Socket: 13
Proto: 17
Src IP: 10.10.10.1
port: 38663
Dst IP: 192.168.10.1
port: 1813
Code: (4) Accounting-Request
Id: 228
Length: 402
Vector: f7b475080067ddd6eb3713f0b58f6152
Data: 01 0d 74 65 73 74 5f 62 67 62 72 61 73
20 0a 64 65 6d 6f 2d 62 6e 67
04 06 4e 8e 20 46
05 06 00 00 00 00
57 09 76 6c 61 6e 31 30 30
3d 06 00 00 00 05
06 06 00 00 00 02
07 06 00 00 00 01
1f 13 66 36 3a 63 62 3a 66 36 3a 34 30 3a 31 66 3a 61
30
1e 13 31 61 3a 32 37 3a 62 35 3a 32 37 3a 62 62 3a 35
33
19 bd 63 75 69 3d 74 65 73 74 5f 62 67 62 72 61 73 2c
73 75 3d 39 34 32 30 33 39 2c 73 6b 3d 72 6a 70
36 6a 6f 65 6e 66 75 61 68 2c 62 6b 69 64 3d 32
32 35 34 30 30 38 39 2c 62 6b 72 69 64 3d 33 2c
6d 76 3d 35 32 39 31 35 31 38 30 30 39 39 37 2c
6d 74 3d 36 30 34 38 31 35 2c 67 6d 74 3d 36 30
34 38 30 30 2c 73 70 3d 31 2c 73 72 3d 2c 61 63
3d 31 2c 75 69 3d 39 34 32 30 33 39 2c 63 63 69
3d 31 38 38 2c 63 63 3d 47 65 6e 65 72 61 6c 2c
61 73 3d 31 2c 63 6f 3d 2c 64 62 3d 31 30 32 34
30 30 2c 75 62 3d 31 30 32 34 30 30 2c 63 62 6b
69 64 3d 32 32 35 34 30 30 39 30
28 06 00 00 00 01
2d 06 00 00 00 01
2c 12 34 65 34 38 64 32 32 34 64 66 36 66 30 63 31 30
2e 06 00 00 00 00
2a 06 00 00 00 00
2b 06 00 00 00 00
2f 06 00 00 00 00
30 06 00 00 00 00
34 06 00 00 00 00
35 06 00 00 00 00
08 06 0a 00 00 01
37 06 63 7e 4c 1d
29 06 00 00 00 8e
21 03 30
Wed Nov 23 22:09:07 2022 : Debug: Waking up in 0.3 seconds.
Socket: 13
Proto: 0
Src IP: 192.168.10.1
port: 1813
Dst IP: 10.10.10.1
port: 38663
Code: (5) Accounting-Response
Id: 228
Length: 20
Vector: 413e6e6bca980f259311bff73799d788
Wed Nov 23 22:09:07 2022 : Debug: Ignoring spoofed proxy reply. Signature is invalid
Wed Nov 23 22:09:07 2022 : Debug: Waking up in 0.1 seconds.
Wed Nov 23 22:09:07 2022 : Debug: (3) Expecting proxy response no later than 5.666255 seconds from now
Wed Nov 23 22:09:07 2022 : Debug: Waking up in 1.6 seconds.
Wed Nov 23 22:09:09 2022 : Error: No response to status check 2 ID 131 for home server 192.168.10.1 port 1813
Wed Nov 23 22:09:09 2022 : Debug: Waking up in 3.9 seconds.
Wed Nov 23 22:09:13 2022 : Debug: (3) No proxy response, giving up on request and marking it done
Wed Nov 23 22:09:13 2022 : ERROR: (3) Failing proxied request for user "test_bgbras", due to lack of any response from home server 192.168.10.1 port 1813
Wed Nov 23 22:09:13 2022 : Debug: (3) Clearing existing &reply: attributes
Wed Nov 23 22:09:13 2022 : Debug: (3) Found Post-Proxy-Type Fail-Accounting
Wed Nov 23 22:09:13 2022 : Debug: (3) server home.example.com {
Wed Nov 23 22:09:13 2022 : Debug: (3) # Executing group from file /etc/freeradius/sites-enabled/robust-proxy-accounting
Wed Nov 23 22:09:13 2022 : Debug: (3) Post-Proxy-Type Fail-Accounting {
Wed Nov 23 22:09:13 2022 : Debug: (3) modsingle[post-proxy]: calling detail.example.com (rlm_detail)
Wed Nov 23 22:09:13 2022 : Debug: /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G
Wed Nov 23 22:09:13 2022 : Debug: Parsed xlat tree:
Wed Nov 23 22:09:13 2022 : Debug: literal --> /var/log/freeradius/radacct/detail.example.com/detail-
Wed Nov 23 22:09:13 2022 : Debug: percent --> Y
Wed Nov 23 22:09:13 2022 : Debug: percent --> m
Wed Nov 23 22:09:13 2022 : Debug: percent --> d
Wed Nov 23 22:09:13 2022 : Debug: literal --> :
Wed Nov 23 22:09:13 2022 : Debug: percent --> H
Wed Nov 23 22:09:13 2022 : Debug: literal --> :
Wed Nov 23 22:09:13 2022 : Debug: percent --> G
Wed Nov 23 22:09:13 2022 : Debug: (3) detail.example.com: EXPAND /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G
Wed Nov 23 22:09:13 2022 : Debug: (3) detail.example.com: --> /var/log/freeradius/radacct/detail.example.com/detail-20221123:22:09
Wed Nov 23 22:09:13 2022 : Debug: (3) detail.example.com: /var/log/freeradius/radacct/detail.example.com/detail-%Y%m%d:%H:%G expands to /var/log/freeradius/radacct/detail.example.com/detail-20221123:22:09
Wed Nov 23 22:09:13 2022 : WARNING: (3) detail.example.com: Suppressing infinite loop
Wed Nov 23 22:09:13 2022 : Debug: (3) modsingle[post-proxy]: returned from detail.example.com (rlm_detail)
Wed Nov 23 22:09:13 2022 : Debug: (3) [detail.example.com] = noop
Wed Nov 23 22:09:13 2022 : Debug: (3) } # Post-Proxy-Type Fail-Accounting = noop
Wed Nov 23 22:09:13 2022 : Debug: (3) }
Wed Nov 23 22:09:13 2022 : Debug: (3) detail (/var/log/freeradius/radacct/detail.example.com/detail-*:*): No response to request. Will retry in 30 seconds
Wed Nov 23 22:09:13 2022 : Debug: (3) Finished request
Wed Nov 23 22:09:13 2022 : Debug: (3) Cleaning up request packet ID 0 with timestamp +36 due to done
Wed Nov 23 22:09:13 2022 : Debug: Waking up in 22.9 seconds.
^CEXIT(2) CALLED src/main/radiusd.c[778]. Last error was: Received Accounting-Response packet from home server 192.168.10.1 port 1813 with invalid Response Authenticator! (Shared secret is incorrect.)
> On 23 Nov 2022, at 16:58, Alan DeKok <aland at deployingradius.com> wrote:
>
> On Nov 23, 2022, at 9:55 AM, Martin Zaharinov <micron10 at gmail.com> wrote:
>> i try to switch from freeradius 2.2.10 to 3.2.1
>> After fix all configs and dictionary
>
> As we said on the GitHub issue, just install 3.2.1. There's no need to "fix" the dictionaries.
>
> You do need to upgrade your v2 configuration to v3. This is documented in raddb/README.rst
>
>> May be i make wrong config or ?
>>
>> See log :
>
> Read it?
>
>> ...
>> Wed Nov 23 20:08:23 2022 : Debug: (0) Proxying request to home server 192.168.10.1 port 1813 timeout 6.000000
>> Wed Nov 23 20:08:23 2022 : Debug: Waking up in 0.3 seconds.
>> Wed Nov 23 20:08:23 2022 : Debug: Ignoring spoofed proxy reply. Signature is invalid
>
> Hmm... that seems interesting.
>
> Maybe check the shared secrets?
>
> We very much recommend reading the debug output.
>
> Alan DeKok.
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
More information about the Freeradius-Users
mailing list