RADIUS failing to start correctly when remote DB is unavailable.
Sea Gull
seagull0044 at gmail.com
Tue Oct 11 13:38:12 UTC 2022
Hi,
Good afternoon! I have a setup where RADIUS is set to write to multiple DBs
simultaneously. I have set this as follows:
1. Copied the SQL instance in /etc/raddb/mods-enabled/sql and had it
renamed and configured accordingly.
2. Called them both
3. In the pool, I have set start=0
4. Set read_client to no
Although from debug these seem to be correctly set, I am still getting the
message that RADIUS is trying to connect to the DB when it is unavailable.
After quite a number of minutes and 3 retries, RADIUS fails to start. I
have attached the full debug and included some explanation too along the
way.
Thanks in advance.
Kind Regards,
SG
-------------- next part --------------
[root at TST02_RADAUTH01_PG_COMPILE ~]# radiusd -X
FreeRADIUS Version 3.0.25
Copyright (C) 1999-2021 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file /usr/local/share/freeradius/dictionary
including dictionary file /usr/local/share/freeradius/dictionary.dhcp
including dictionary file /usr/local/share/freeradius/dictionary.vqp
including dictionary file /etc/raddb/dictionary
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/mods-enabled/
including configuration file /etc/raddb/mods-enabled/always
including configuration file /etc/raddb/mods-enabled/attr_filter
including configuration file /etc/raddb/mods-enabled/cache_eap
including configuration file /etc/raddb/mods-enabled/chap
including configuration file /etc/raddb/mods-enabled/date
including configuration file /etc/raddb/mods-enabled/detail
including configuration file /etc/raddb/mods-enabled/detail.log
including configuration file /etc/raddb/mods-enabled/digest
including configuration file /etc/raddb/mods-enabled/dynamic_clients
including configuration file /etc/raddb/mods-enabled/eap
including configuration file /etc/raddb/mods-enabled/echo
including configuration file /etc/raddb/mods-enabled/exec
including configuration file /etc/raddb/mods-enabled/expiration
including configuration file /etc/raddb/mods-enabled/expr
including configuration file /etc/raddb/mods-enabled/files
including configuration file /etc/raddb/mods-enabled/linelog
including configuration file /etc/raddb/mods-enabled/logintime
including configuration file /etc/raddb/mods-enabled/mschap
including configuration file /etc/raddb/mods-enabled/ntlm_auth
including configuration file /etc/raddb/mods-enabled/pap
including configuration file /etc/raddb/mods-enabled/passwd
including configuration file /etc/raddb/mods-enabled/preprocess
including configuration file /etc/raddb/mods-enabled/radutmp
including configuration file /etc/raddb/mods-enabled/realm
including configuration file /etc/raddb/mods-enabled/replicate
including configuration file /etc/raddb/mods-enabled/soh
including configuration file /etc/raddb/mods-enabled/sradutmp
including configuration file /etc/raddb/mods-enabled/totp
including configuration file /etc/raddb/mods-enabled/unix
including configuration file /etc/raddb/mods-enabled/unpack
including configuration file /etc/raddb/mods-enabled/utf8
including configuration file /etc/raddb/mods-enabled/ldap
including configuration file /etc/raddb/mods-enabled/sql
including configuration file /etc/raddb/mods-config/sql/main/postgresql/queries.conf
including configuration file /etc/raddb/mods-enabled/sql_local
including configuration file /etc/raddb/mods-config/sql/main/postgresql/queries.conf
including configuration file /etc/raddb/mods-enabled/sql_remote
including configuration file /etc/raddb/mods-config/sql/main/postgresql/queries.conf
including files in directory /etc/raddb/policy.d/
including configuration file /etc/raddb/policy.d/abfab-tr
including configuration file /etc/raddb/policy.d/accounting
including configuration file /etc/raddb/policy.d/canonicalization
including configuration file /etc/raddb/policy.d/control
including configuration file /etc/raddb/policy.d/cui
including configuration file /etc/raddb/policy.d/debug
including configuration file /etc/raddb/policy.d/dhcp
including configuration file /etc/raddb/policy.d/eap
including configuration file /etc/raddb/policy.d/filter
including configuration file /etc/raddb/policy.d/moonshot-targeted-ids
including configuration file /etc/raddb/policy.d/operator-name
including configuration file /etc/raddb/policy.d/rfc7542
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
including configuration file /etc/raddb/sites-enabled/inner-tunnel
main {
security {
user = "radiusd"
group = "radiusd"
allow_core_dumps = no
}
name = "radiusd"
prefix = "/usr"
localstatedir = "/var"
logdir = "/var/log/radius"
run_dir = "/var/run/radiusd"
}
main {
name = "radiusd"
prefix = "/usr"
localstatedir = "/var"
sbindir = "/usr/sbin"
logdir = "/var/log/radius"
run_dir = "/var/run/radiusd"
libdir = "/usr/lib64/freeradius"
radacctdir = "/var/log/radius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 16384
postauth_client_lost = no
pidfile = "/var/run/radiusd/radiusd.pid"
checkrad = "/usr/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = no
auth_badpass = no
auth_testodpass = no
colourise = yes
msg_denied = "You are already logged in - access denied"
}
resources {
}
security {
max_attributes = 200
reject_delay = 1.000000
status_server = yes
allow_vulnerable_openssl = "no"
}
}
radiusd: #### Loading Realms and Home Servers ####
home_server proxy{
ipaddr = xx.xx.xx.xx
port = 1813
type = "acct"
secret = <<< secret >>>
response_window = 60.000000
response_timeouts = 1
max_outstanding = 500
zombie_period = 40
status_check = "none"
ping_interval = 30
check_interval = 30
check_timeout = 4
num_answers_to_alive = 3
revive_interval = 120
limit {
max_connections = 16
max_requests = 0
lifetime = 0
idle_timeout = 0
}
coa {
irt = 2
mrt = 16
mrc = 5
mrd = 30
}
}
Ignoring "response_window = 60.000000", forcing to "response_window = 30.000000"
home_server_pool proxy_pool {
type = fail-over
home_server = proxy
}
realm test{
acct_pool = proxy_pool
}
radiusd: #### Loading Clients ####
client bbkrt1 {
ipaddr = yy.yy.yy.yy
require_message_authenticator = no
secret = <<< secret >>>
nas_type = "cisco"
proto = "*"
limit {
max_connections = 0
lifetime = 0
idle_timeout = 30
}
}
client bbkrt1_lo1 {
ipaddr = zz.zz.zz.zz
require_message_authenticator = no
secret = <<< secret >>>
nas_type = "cisco"
proto = "*"
limit {
max_connections = 0
lifetime = 0
idle_timeout = 30
}
}
Debugger not attached
# Creating Auth-Type = PAP
# Creating Auth-Type = LDAP
# Creating Auth-Type = mschap
# Creating Auth-Type = eap
# Creating Auth-Type = CHAP
# Creating Auth-Type = MS-CHAP
radiusd: #### Instantiating modules ####
modules {
# Loaded module rlm_always
# Loading module "reject" from file /etc/raddb/mods-enabled/always
always reject {
rcode = "reject"
simulcount = 0
mpp = no
}
# Loading module "fail" from file /etc/raddb/mods-enabled/always
always fail {
rcode = "fail"
simulcount = 0
mpp = no
}
# Loading module "ok" from file /etc/raddb/mods-enabled/always
always ok {
rcode = "ok"
simulcount = 0
mpp = no
}
# Loading module "handled" from file /etc/raddb/mods-enabled/always
always handled {
rcode = "handled"
simulcount = 0
mpp = no
}
# Loading module "invalid" from file /etc/raddb/mods-enabled/always
always invalid {
rcode = "invalid"
simulcount = 0
mpp = no
}
# Loading module "userlock" from file /etc/raddb/mods-enabled/always
always userlock {
rcode = "userlock"
simulcount = 0
mpp = no
}
# Loading module "notfound" from file /etc/raddb/mods-enabled/always
always notfound {
rcode = "notfound"
simulcount = 0
mpp = no
}
# Loading module "noop" from file /etc/raddb/mods-enabled/always
always noop {
rcode = "noop"
simulcount = 0
mpp = no
}
# Loading module "updated" from file /etc/raddb/mods-enabled/always
always updated {
rcode = "updated"
simulcount = 0
mpp = no
}
# Loaded module rlm_attr_filter
# Loading module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.post-proxy {
filename = "/etc/raddb/mods-config/attr_filter/post-proxy"
key = "%{Realm}"
relaxed = no
}
# Loading module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.pre-proxy {
filename = "/etc/raddb/mods-config/attr_filter/pre-proxy"
key = "%{Realm}"
relaxed = no
}
# Loading module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.access_reject {
filename = "/etc/raddb/mods-config/attr_filter/access_reject"
key = "%{User-Name}"
relaxed = no
}
# Loading module "attr_filter.access_challenge" from file /etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.access_challenge {
filename = "/etc/raddb/mods-config/attr_filter/access_challenge"
key = "%{User-Name}"
relaxed = no
}
# Loading module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter
attr_filter attr_filter.accounting_response {
filename = "/etc/raddb/mods-config/attr_filter/accounting_response"
key = "%{User-Name}"
relaxed = no
}
# Loaded module rlm_cache
# Loading module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap
cache cache_eap {
driver = "rlm_cache_rbtree"
key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}"
ttl = 15
max_entries = 0
epoch = 0
add_stats = no
}
# Loaded module rlm_chap
# Loading module "chap" from file /etc/raddb/mods-enabled/chap
# Loaded module rlm_date
# Loading module "date" from file /etc/raddb/mods-enabled/date
date {
format = "%b %e %Y %H:%M:%S %Z"
utc = no
}
# Loading module "wispr2date" from file /etc/raddb/mods-enabled/date
date wispr2date {
format = "%Y-%m-%dT%H:%M:%S"
utc = no
}
# Loaded module rlm_detail
# Loading module "detail" from file /etc/raddb/mods-enabled/detail
detail {
filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "auth_log" from file /etc/raddb/mods-enabled/detail.log
detail auth_log {
filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "reply_log" from file /etc/raddb/mods-enabled/detail.log
detail reply_log {
filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log
detail pre_proxy_log {
filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loading module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log
detail post_proxy_log {
filename = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d"
header = "%t"
permissions = 384
locking = no
escape_filenames = no
log_packet_header = no
}
# Loaded module rlm_digest
# Loading module "digest" from file /etc/raddb/mods-enabled/digest
# Loaded module rlm_dynamic_clients
# Loading module "dynamic_clients" from file /etc/raddb/mods-enabled/dynamic_clients
# Loaded module rlm_eap
# Loading module "eap" from file /etc/raddb/mods-enabled/eap
eap {
default_eap_type = "md5"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 16384
}
# Loaded module rlm_exec
# Loading module "echo" from file /etc/raddb/mods-enabled/echo
exec echo {
wait = yes
program = "/bin/echo %{User-Name}"
input_pairs = "request"
output_pairs = "reply"
shell_escape = yes
}
# Loading module "exec" from file /etc/raddb/mods-enabled/exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
timeout = 10
}
# Loaded module rlm_expiration
# Loading module "expiration" from file /etc/raddb/mods-enabled/expiration
# Loaded module rlm_expr
# Loading module "expr" from file /etc/raddb/mods-enabled/expr
expr {
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
}
# Loaded module rlm_files
# Loading module "files" from file /etc/raddb/mods-enabled/files
files {
filename = "/etc/raddb/mods-config/files/authorize"
acctusersfile = "/etc/raddb/mods-config/files/accounting"
preproxy_usersfile = "/etc/raddb/mods-config/files/pre-proxy"
}
# Loaded module rlm_linelog
# Loading module "linelog" from file /etc/raddb/mods-enabled/linelog
linelog {
filename = "/var/log/radius/linelog"
escape_filenames = no
syslog_severity = "info"
permissions = 384
format = "This is a log message for %{User-Name}"
reference = "messages.%{%{reply:Packet-Type}:-default}"
}
# Loading module "log_accounting" from file /etc/raddb/mods-enabled/linelog
linelog log_accounting {
filename = "/var/log/radius/linelog-accounting"
escape_filenames = no
syslog_severity = "info"
permissions = 384
format = ""
reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
}
# Loaded module rlm_logintime
# Loading module "logintime" from file /etc/raddb/mods-enabled/logintime
logintime {
minimum_timeout = 60
}
# Loaded module rlm_mschap
# Loading module "mschap" from file /etc/raddb/mods-enabled/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = yes
passchange {
}
allow_retry = yes
winbind_retry_with_normalised_username = no
}
# Loading module "ntlm_auth" from file /etc/raddb/mods-enabled/ntlm_auth
exec ntlm_auth {
wait = yes
program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
shell_escape = yes
}
# Loaded module rlm_pap
# Loading module "pap" from file /etc/raddb/mods-enabled/pap
pap {
normalise = yes
}
# Loaded module rlm_passwd
# Loading module "etc_passwd" from file /etc/raddb/mods-enabled/passwd
passwd etc_passwd {
filename = "/etc/passwd"
format = "*User-Name:Crypt-Password:"
delimiter = ":"
ignore_nislike = no
ignore_empty = yes
allow_multiple_keys = no
hash_size = 100
}
# Loaded module rlm_preprocess
# Loading module "preprocess" from file /etc/raddb/mods-enabled/preprocess
preprocess {
huntgroups = "/etc/raddb/mods-config/preprocess/huntgroups"
hints = "/etc/raddb/mods-config/preprocess/hints"
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
with_alvarion_vsa_hack = no
}
# Loaded module rlm_radutmp
# Loading module "radutmp" from file /etc/raddb/mods-enabled/radutmp
radutmp {
filename = "/var/log/radius/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
permissions = 384
caller_id = yes
}
# Loaded module rlm_realm
# Loading module "IPASS" from file /etc/raddb/mods-enabled/realm
realm IPASS {
format = "prefix"
delimiter = "/"
ignore_default = no
ignore_null = no
}
# Loading module "suffix" from file /etc/raddb/mods-enabled/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = no
}
# Loading module "bangpath" from file /etc/raddb/mods-enabled/realm
realm bangpath {
format = "prefix"
delimiter = "!"
ignore_default = no
ignore_null = no
}
# Loading module "realmpercent" from file /etc/raddb/mods-enabled/realm
realm realmpercent {
format = "suffix"
delimiter = "%"
ignore_default = no
ignore_null = no
}
# Loading module "ntdomain" from file /etc/raddb/mods-enabled/realm
realm ntdomain {
format = "prefix"
delimiter = "\\"
ignore_default = no
ignore_null = no
}
# Loaded module rlm_replicate
# Loading module "replicate" from file /etc/raddb/mods-enabled/replicate
# Loaded module rlm_soh
# Loading module "soh" from file /etc/raddb/mods-enabled/soh
soh {
dhcp = yes
}
# Loading module "sradutmp" from file /etc/raddb/mods-enabled/sradutmp
radutmp sradutmp {
filename = "/var/log/radius/sradutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
permissions = 420
caller_id = no
}
# Loaded module rlm_totp
# Loading module "totp" from file /etc/raddb/mods-enabled/totp
# Loaded module rlm_unix
# Loading module "unix" from file /etc/raddb/mods-enabled/unix
unix {
radwtmp = "/var/log/radius/radwtmp"
}
Creating attribute Unix-Group
# Loaded module rlm_unpack
# Loading module "unpack" from file /etc/raddb/mods-enabled/unpack
# Loaded module rlm_utf8
# Loading module "utf8" from file /etc/raddb/mods-enabled/utf8
# Loaded module rlm_ldap
# Loading module "ldap" from file /etc/raddb/mods-enabled/ldap
ldap {
server = "localhost"
port = 389
identity = "uid=superradius,ou=people,dc=netnet,dc=net"
password = <<< secret >>>
sasl {
}
user_dn = "LDAP-UserDn"
user {
scope = "sub"
access_positive = yes
sasl {
}
}
group {
filter = "(objectClass=posixGroup)"
scope = "sub"
name_attribute = "cn"
membership_attribute = "memberOf"
cacheable_name = no
cacheable_dn = no
allow_dangling_group_ref = no
}
client {
filter = "(objectClass=radiusClient)"
scope = "sub"
base_dn = "ou=people,dc=netnet,dc=net"
}
profile {
}
options {
ldap_debug = 40
chase_referrals = yes
rebind = yes
net_timeout = 1
res_timeout = 10
srv_timelimit = 3
idle = 60
probes = 3
interval = 3
}
tls {
start_tls = no
}
}
Creating attribute LDAP-Group
# Loaded module rlm_sql
# Loading module "sql" from file /etc/raddb/mods-enabled/sql
sql sql {
driver = "rlm_sql_postgresql"
server = ""
port = 0
login = ""
password = <<< secret >>>
radius_db = "dbname=radius host=127.0.0.1 user=radius password=password"
read_groups = yes
read_profiles = yes
read_clients = no
delete_stale_sessions = yes
sql_user_name = "%{%{Stripped-User-Name}:-%{%{User-Name}:-none}}"
default_user_profile = ""
client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
authorize_check_query = "SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_reply_query = "SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_group_check_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '%{sql-SQL-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '%{sql-SQL-Group}' ORDER BY id"
group_membership_query = "SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority"
simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
auto_escape = no
accounting {
reference = "%{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}"
type {
accounting-on {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
accounting-off {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
start {
query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL"
}
interim-update {
query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInterval = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM (COALESCE(AcctUpdateTime, AcctStartTime)))), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint) WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
stop {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
}
}
post-auth {
reference = ".query"
query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', NOW())"
}
}
rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
Creating attribute sql-SQL-Group
# Loading module "sql_local" from file /etc/raddb/mods-enabled/sql_local
sql sql_local {
driver = "rlm_sql_postgresql"
server = ""
port = 0
login = ""
password = <<< secret >>>
radius_db = "dbname=radius host=127.0.0.1 user=radius password=password"
read_groups = yes
read_profiles = yes
read_clients = no
delete_stale_sessions = yes
sql_user_name = "%{%{Stripped-User-Name}:-%{%{User-Name}:-none}}"
default_user_profile = ""
client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
authorize_check_query = "SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_reply_query = "SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_group_check_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '%{sql_local-SQL-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '%{sql_local-SQL-Group}' ORDER BY id"
group_membership_query = "SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority"
simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
auto_escape = no
accounting {
reference = "%{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}"
type {
accounting-on {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
accounting-off {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
start {
query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL"
}
interim-update {
query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInterval = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM (COALESCE(AcctUpdateTime, AcctStartTime)))), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint) WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
stop {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
}
}
post-auth {
reference = ".query"
query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', NOW())"
}
}
rlm_sql (sql_local): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
Creating attribute sql_local-SQL-Group
# Loading module "sql_remote" from file /etc/raddb/mods-enabled/sql_remote
sql sql_remote {
driver = "rlm_sql_postgresql"
server = ""
port = 0
login = ""
password = <<< secret >>>
radius_db = "dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668"
read_groups = yes
read_profiles = yes
read_clients = no
delete_stale_sessions = yes
sql_user_name = "%{%{Stripped-User-Name}:-%{%{User-Name}:-none}}"
default_user_profile = ""
client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas"
authorize_check_query = "SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_reply_query = "SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id"
authorize_group_check_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupcheck WHERE GroupName = '%{sql_remote-SQL-Group}' ORDER BY id"
authorize_group_reply_query = "SELECT id, GroupName, Attribute, Value, op FROM radgroupreply WHERE GroupName = '%{sql_remote-SQL-Group}' ORDER BY id"
group_membership_query = "SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority"
simul_count_query = "SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
simul_verify_query = "SELECT RadAcctId, AcctSessionId, UserName, NASIPAddress, NASPortId, FramedIPAddress, CallingStationId, FramedProtocol FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL"
safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
auto_escape = no
accounting {
reference = "%{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}"
type {
accounting-on {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
accounting-off {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime))), AcctTerminateCause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE AcctStopTime IS NULL AND NASIPAddress= '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}' AND AcctStartTime <= '%S'::timestamp"
}
start {
query = "INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL"
}
interim-update {
query = "UPDATE radacct SET FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInterval = (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM (COALESCE(AcctUpdateTime, AcctStartTime)))), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint) WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
stop {
query = "UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL"
}
}
}
post-auth {
reference = ".query"
query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', NOW())"
}
}
rlm_sql (sql_remote): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
Creating attribute sql_remote-SQL-Group
instantiate {
}
# Instantiating module "reject" from file /etc/raddb/mods-enabled/always
# Instantiating module "fail" from file /etc/raddb/mods-enabled/always
# Instantiating module "ok" from file /etc/raddb/mods-enabled/always
# Instantiating module "handled" from file /etc/raddb/mods-enabled/always
# Instantiating module "invalid" from file /etc/raddb/mods-enabled/always
# Instantiating module "userlock" from file /etc/raddb/mods-enabled/always
# Instantiating module "notfound" from file /etc/raddb/mods-enabled/always
# Instantiating module "noop" from file /etc/raddb/mods-enabled/always
# Instantiating module "updated" from file /etc/raddb/mods-enabled/always
# Instantiating module "attr_filter.post-proxy" from file /etc/raddb/mods-enabled/attr_filter
reading pairlist file /etc/raddb/mods-config/attr_filter/post-proxy
# Instantiating module "attr_filter.pre-proxy" from file /etc/raddb/mods-enabled/attr_filter
reading pairlist file /etc/raddb/mods-config/attr_filter/pre-proxy
# Instantiating module "attr_filter.access_reject" from file /etc/raddb/mods-enabled/attr_filter
reading pairlist file /etc/raddb/mods-config/attr_filter/access_reject
# Instantiating module "attr_filter.access_challenge" from file /etc/raddb/mods-enabled/attr_filter
reading pairlist file /etc/raddb/mods-config/attr_filter/access_challenge
# Instantiating module "attr_filter.accounting_response" from file /etc/raddb/mods-enabled/attr_filter
reading pairlist file /etc/raddb/mods-config/attr_filter/accounting_response
# Instantiating module "cache_eap" from file /etc/raddb/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked
# Instantiating module "detail" from file /etc/raddb/mods-enabled/detail
# Instantiating module "auth_log" from file /etc/raddb/mods-enabled/detail.log
rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output
# Instantiating module "reply_log" from file /etc/raddb/mods-enabled/detail.log
# Instantiating module "pre_proxy_log" from file /etc/raddb/mods-enabled/detail.log
# Instantiating module "post_proxy_log" from file /etc/raddb/mods-enabled/detail.log
# Instantiating module "eap" from file /etc/raddb/mods-enabled/eap
# Linked to sub-module rlm_eap_md5
rlm_eap (EAP): Ignoring EAP method 'leap', because it is no longer supported
# Linked to sub-module rlm_eap_gtc
gtc {
challenge = "Password: "
auth_type = "PAP"
}
# Linked to sub-module rlm_eap_tls
tls {
tls = "tls-common"
}
tls-config tls-common {
verify_depth = 0
ca_path = "/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/etc/raddb/certs/server.pem"
certificate_file = "/etc/raddb/certs/server.pem"
ca_file = "/etc/raddb/certs/ca.pem"
private_key_password = <<< secret >>>
dh_file = "/etc/raddb/certs/dh"
fragment_size = 1024
include_length = yes
auto_chain = yes
check_crl = no
check_all_crl = no
ca_path_reload_interval = 0
cipher_list = "PROFILE=SYSTEM"
cipher_server_preference = no
reject_unknown_intermediate_ca = no
ecdh_curve = "prime256v1"
disable_tlsv1 = yes
disable_tlsv1_1 = yes
tls_max_version = "1.2"
tls_min_version = "1.2"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
skip_if_ocsp_ok = no
}
ocsp {
enable = no
override_cert_url = yes
url = "http://127.0.0.1/ocsp/"
use_nonce = yes
timeout = 0
softfail = no
}
}
tls: Please use 'tls_min_version' and 'tls_max_version' instead of 'disable_tlsv1'
tls: Please use 'tls_min_version' and 'tls_max_version' instead of 'disable_tlsv1_1'
# Linked to sub-module rlm_eap_ttls
ttls {
tls = "tls-common"
default_eap_type = "md5"
copy_request_to_tunnel = no
use_tunneled_reply = no
virtual_server = "inner-tunnel"
include_length = yes
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_peap
peap {
tls = "tls-common"
default_eap_type = "mschapv2"
copy_request_to_tunnel = no
use_tunneled_reply = no
proxy_tunneled_request_as_eap = yes
virtual_server = "inner-tunnel"
soh = no
require_client_cert = no
}
tls: Using cached TLS configuration from previous invocation
# Linked to sub-module rlm_eap_mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
# Instantiating module "expiration" from file /etc/raddb/mods-enabled/expiration
# Instantiating module "files" from file /etc/raddb/mods-enabled/files
reading pairlist file /etc/raddb/mods-config/files/authorize
reading pairlist file /etc/raddb/mods-config/files/accounting
reading pairlist file /etc/raddb/mods-config/files/pre-proxy
# Instantiating module "linelog" from file /etc/raddb/mods-enabled/linelog
# Instantiating module "log_accounting" from file /etc/raddb/mods-enabled/linelog
# Instantiating module "logintime" from file /etc/raddb/mods-enabled/logintime
# Instantiating module "mschap" from file /etc/raddb/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
# Instantiating module "pap" from file /etc/raddb/mods-enabled/pap
# Instantiating module "etc_passwd" from file /etc/raddb/mods-enabled/passwd
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
# Instantiating module "preprocess" from file /etc/raddb/mods-enabled/preprocess
reading pairlist file /etc/raddb/mods-config/preprocess/huntgroups
reading pairlist file /etc/raddb/mods-config/preprocess/hints
# Instantiating module "IPASS" from file /etc/raddb/mods-enabled/realm
# Instantiating module "suffix" from file /etc/raddb/mods-enabled/realm
# Instantiating module "bangpath" from file /etc/raddb/mods-enabled/realm
# Instantiating module "realmpercent" from file /etc/raddb/mods-enabled/realm
# Instantiating module "ntdomain" from file /etc/raddb/mods-enabled/realm
# Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap
rlm_ldap: libldap vendor: OpenLDAP, version: 20446
accounting {
reference = "%{tolower:type.%{Acct-Status-Type}}"
}
post-auth {
reference = "."
}
rlm_ldap (ldap): Initialising connection pool
pool {
start = 5
min = 3
max = 32
spare = 10
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 30
spread = no
}
rlm_ldap (ldap): Opening additional connection (0), 1 of 32 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (1), 1 of 31 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (2), 1 of 30 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (3), 1 of 29 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Opening additional connection (4), 1 of 28 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
# Instantiating module "sql" from file /etc/raddb/mods-enabled/sql
postgresql {
send_application_name = yes
}
rlm_sql (sql): Attempting to connect to database "dbname=radius host=127.0.0.1 user=radius password=password"
rlm_sql (sql): Initialising connection pool
pool {
start = 0
min = 3
max = 32
spare = 10
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 30
spread = no
}
# Instantiating module "sql_local" from file /etc/raddb/mods-enabled/sql_local
postgresql {
send_application_name = yes
}
rlm_sql (sql_local): Attempting to connect to database "dbname=radius host=127.0.0.1 user=radius password=password"
rlm_sql (sql_local): Initialising connection pool
pool {
start = 0
min = 3
max = 32
spare = 10
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 30
spread = no
}
# Instantiating module "sql_remote" from file /etc/raddb/mods-enabled/sql_remote
postgresql {
send_application_name = yes
}
rlm_sql (sql_remote): Attempting to connect to database "dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668"
rlm_sql (sql_remote): Initialising connection pool
pool {
start = 0
min = 3
max = 32
spare = 10
uses = 0
lifetime = 0
cleanup_interval = 30
idle_timeout = 60
retry_delay = 30
spread = no
}
} # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /etc/raddb/radiusd.conf
} # server
server default { # from file /etc/raddb/sites-enabled/default
# Loading authenticate {...}
Compiling Auth-Type PAP for attr Auth-Type
Compiling Auth-Type LDAP for attr Auth-Type
# Loading authorize {...}
# Loading preacct {...}
# Loading accounting {...}
# Loading post-auth {...}
Compiling Post-Auth-Type REJECT for attr Post-Auth-Type
Compiling Post-Auth-Type Challenge for attr Post-Auth-Type
} # server default
server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
# Loading authenticate {...}
Compiling Auth-Type PAP for attr Auth-Type
Compiling Auth-Type CHAP for attr Auth-Type
Compiling Auth-Type MS-CHAP for attr Auth-Type
# Loading authorize {...}
# Loading session {...}
# Loading post-proxy {...}
# Loading post-auth {...}
# Skipping contents of 'if' as it is always 'false' -- /etc/raddb/sites-enabled/inner-tunnel:336
Compiling Post-Auth-Type REJECT for attr Post-Auth-Type
} # server inner-tunnel
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
limit {
max_connections = 16
lifetime = 0
idle_timeout = 30
}
}
listen {
type = "acct"
ipaddr = *
port = 0
limit {
max_connections = 16
lifetime = 0
idle_timeout = 30
}
}
listen {
type = "auth"
ipv6addr = ::
port = 0
limit {
max_connections = 16
lifetime = 0
idle_timeout = 30
}
}
listen {
type = "acct"
ipv6addr = ::
port = 0
limit {
max_connections = 16
lifetime = 0
idle_timeout = 30
}
}
listen {
type = "auth"
ipaddr = 127.0.0.1
port = 18120
}
Listening on auth address * port 1812 bound to server default
Listening on acct address * port 1813 bound to server default
Listening on auth address :: port 1812 bound to server default
Listening on acct address :: port 1813 bound to server default
Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel
Listening on proxy address * port 33091
Listening on proxy address :: port 47940
Ready to process requests
(0) Received Access-Request Id 37 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1812 length 195
(0) Framed-Protocol = PPP
(0) User-Name = "ctest at test"
(0) User-Password = "12312312"
(0) Calling-Station-Id = "GPN02013_testing"
(0) NAS-Port-Type = Ethernet
(0) NAS-Port = 134218230
(0) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(0) Service-Type = Framed-User
(0) NAS-IP-Address = zz.zz.zz.zz
(0) Acct-Session-Id = "0/1/0/502_0012FC83"
(0) NAS-Identifier = "bbkrt1"
(0) # Executing section authorize from file /etc/raddb/sites-enabled/default
(0) authorize {
(0) preprocess: hints: Matched DEFAULT at 64
(0) [preprocess] = ok
(0) suffix: Checking for suffix after "@"
(0) suffix: Looking up realm "test" for User-Name = "ctest at test"
(0) suffix: Found realm "test"
(0) suffix: Adding Stripped-User-Name = "ctest"
(0) suffix: Adding Realm = "test"
(0) suffix: Authentication realm is LOCAL
(0) [suffix] = ok
(0) files: users: Matched entry DEFAULT at line 80
(0) files: EXPAND /etc/raddb/custom_scripts/access.pl %{User-Name} %{NAS-IP-Address} %{NAS-Port} %{NAS-Port-Type} %{Cisco-AVPair[0]}
(0) files: --> /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet
(0) [files] = ok
rlm_ldap (ldap): Reserved connection (0)
(0) ldap: EXPAND (uid=%{Stripped-User-Name})
(0) ldap: --> (uid=ctest)
(0) ldap: Performing search in "ou=people,dc=netnet,dc=net" with filter "(uid=ctest)", scope "sub"
(0) ldap: Waiting for search result...
(0) ldap: User object found at DN "uid=ctest,ou=People,dc=netnet,dc=net"
(0) ldap: Processing user attributes
(0) ldap: control:Password-With-Header += '{MD5}GBRnMlwaST+2lP39MIFptA=='
rlm_ldap (ldap): Released connection (0)
Need more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
(0) [ldap] = updated
(0) [expiration] = noop
(0) [logintime] = noop
(0) pap: Converted: &control:Password-With-Header -> &control:MD5-Password
(0) pap: Removing &control:Password-With-Header
(0) pap: Normalizing MD5-Password from base64 encoding, 24 bytes -> 16 bytes
(0) pap: WARNING: Auth-Type already set. Not setting to PAP
(0) [pap] = noop
(0) } # authorize = updated
(0) Found Auth-Type = LDAP
(0) # Executing group from file /etc/raddb/sites-enabled/default
(0) Auth-Type LDAP {
rlm_ldap (ldap): Reserved connection (1)
(0) ldap: Login attempt by "ctest"
(0) ldap: Using user DN from request "uid=ctest,ou=People,dc=netnet,dc=net"
(0) ldap: Waiting for bind result...
(0) ldap: Bind successful
(0) ldap: Bind as user "uid=ctest,ou=People,dc=netnet,dc=net" was successful
rlm_ldap (ldap): Released connection (1)
(0) [ldap] = ok
(0) } # Auth-Type LDAP = ok
(0) # Executing section post-auth from file /etc/raddb/sites-enabled/default
(0) post-auth {
(0) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) {
(0) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) -> FALSE
(0) update {
(0) No attributes updated for RHS &session-state:
(0) } # update = noop
(0) exec: Executing: /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet :
(0) exec: Program returned code (0) and output 'Framed-IP-Netmask = 255.255.255.255, Framed-MTU = 1492, Service-Type = Framed-User, Framed-Protocol = PPP, Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx", Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227", Cisco-AVPair += "accounting-list=UAT_TST02", Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"'
(0) exec: Program executed successfully
(0) [exec] = ok
(0) policy remove_reply_message_if_eap {
(0) if (&reply:EAP-Message && &reply:Reply-Message) {
(0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(0) else {
(0) [noop] = noop
(0) } # else = noop
(0) } # policy remove_reply_message_if_eap = noop
(0) } # post-auth = ok
(0) Sent Access-Accept Id 37 from xx.xx.xx.xx:1812 to zz.zz.zz.zz:21678 length 245
(0) Framed-IP-Netmask = 255.255.255.255
(0) Framed-MTU = 1492
(0) Service-Type = Framed-User
(0) Framed-Protocol = PPP
(0) Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx"
(0) Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227"
(0) Cisco-AVPair += "accounting-list=UAT_TST02"
(0) Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Accounting-Request Id 38 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1813 length 203
(1) Acct-Session-Id = "0/1/0/502_0012FC83"
(1) Framed-Protocol = PPP
(1) Framed-IP-Address = 10.10.10.10
(1) User-Name = "ctest at test"
(1) Acct-Authentic = RADIUS
(1) Acct-Status-Type = Start
(1) Calling-Station-Id = "GPN02013_testing"
(1) NAS-Port-Type = Ethernet
(1) NAS-Port = 134218230
(1) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(1) Service-Type = Framed-User
(1) NAS-IP-Address = zz.zz.zz.zz
(1) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(1) Acct-Delay-Time = 0
(1) # Executing section preacct from file /etc/raddb/sites-enabled/default
(1) preacct {
(1) preprocess: hints: Matched DEFAULT at 64
(1) [preprocess] = ok
(1) policy acct_unique {
(1) update request {
(1) &Tmp-String-9 := "ai:"
(1) } # update request = noop
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(1) EXPAND %{hex:&Class}
(1) -->
(1) EXPAND ^%{hex:&Tmp-String-9}
(1) --> ^61693a
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(1) else {
(1) update request {
(1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1) --> 2b083f411e5bfc3b3baed3d31fe210e0
(1) &Acct-Unique-Session-Id := 2b083f411e5bfc3b3baed3d31fe210e0
(1) } # update request = noop
(1) } # else = noop
(1) } # policy acct_unique = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: Looking up realm "test" for User-Name = "ctest at test"
(1) suffix: Found realm "test"
(1) suffix: Adding Stripped-User-Name = "ctest"
(1) suffix: Adding Realm = "test"
(1) suffix: Proxying request from user ctest to realm test
(1) suffix: Preparing to proxy accounting request to realm "test"
(1) [suffix] = updated
(1) [files] = noop
(1) } # preacct = updated
(1) # Executing section accounting from file /etc/raddb/sites-enabled/default
(1) accounting {
(1) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(1) detail: --> /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(1) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(1) detail: EXPAND %t
(1) detail: --> Tue Oct 11 14:28:20 2022
(1) [detail] = ok
(1) [unix] = ok
(1) sql_local: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(1) sql_local: --> type.start.query
(1) sql_local: Using query template 'query'
rlm_sql (sql_local): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql_local): Opening additional connection (0), 1 of 32 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=radius host=127.0.0.1 user=radius password=password application_name='FreeRADIUS 3.0.25 - radiusd (sql_local)'
Connected to database 'radius' on '127.0.0.1' server version 100021, protocol version 3, backend PID 61419
rlm_sql (sql_local): Reserved connection (0)
(1) sql_local: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-none}}
(1) sql_local: --> ctest
(1) sql_local: SQL-User-Name set to 'ctest'
(1) sql_local: EXPAND INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL
(1) sql_local: --> INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491300), TO_TIMESTAMP(1665491300), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491300), AcctUpdateTime = TO_TIMESTAMP(1665491300), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
(1) sql_local: Executing query: INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491300), TO_TIMESTAMP(1665491300), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491300), AcctUpdateTime = TO_TIMESTAMP(1665491300), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(1) sql_local: SQL query returned: success
(1) sql_local: 1 record(s) updated
rlm_sql (sql_local): Released connection (0)
Need 2 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_sql (sql_local): Opening additional connection (1), 1 of 31 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=radius host=127.0.0.1 user=radius password=password application_name='FreeRADIUS 3.0.25 - radiusd (sql_local)'
Connected to database 'radius' on '127.0.0.1' server version 100021, protocol version 3, backend PID 61420
(1) [sql_local] = ok
(1) sql_remote: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(1) sql_remote: --> type.start.query
(1) sql_remote: Using query template 'query'
rlm_sql (sql_remote): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql_remote): Opening additional connection (0), 1 of 32 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668 application_name='FreeRADIUS 3.0.25 - radiusd (sql_remote)'
===============================================================================================================================================================================================================================
At this point, RADIUS still trying to connect to remote DB which is down, and simultaneously the user was disconnected from the BNG.
As soon as doing so, RADIUS showed the below:
===============================================================================================================================================================================================================================
rlm_sql_postgresql: Connection failed: could not connect to server: Connection timed out Is the server running on host "tst02corpdb.corp.net" (172.16.82.37) and accepting TCP/IP connections on port 5432?
rlm_sql_postgresql: Socket destructor called, closing socket
rlm_sql (sql_remote): Opening connection failed (0)
(1) [sql_remote] = fail
(1) } # accounting = fail
(1) Starting proxy to home server xx.xx.xx.xx port 1813
(1) server default {
(1) }
(1) Proxying request to home server xx.xx.xx.xx port 1813 timeout 30.000000
(1) Sent Accounting-Request Id 255 from 0.0.0.0:33091 to xx.xx.xx.xx:1813 length 210
(1) Acct-Session-Id = "0/1/0/502_0012FC83"
(1) Framed-Protocol = PPP
(1) Framed-IP-Address = 10.10.10.10
(1) User-Name = "ctest"
(1) Acct-Authentic = RADIUS
(1) Acct-Status-Type = Start
(1) Calling-Station-Id = "GPN02013_testing"
(1) NAS-Port-Type = Ethernet
(1) NAS-Port = 134218230
(1) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(1) Service-Type = Framed-User
(1) NAS-IP-Address = zz.zz.zz.zz
(1) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(1) Acct-Delay-Time = 0
(1) Event-Timestamp = "Oct 11 2022 14:28:20 CEST"
(1) Proxy-State = 0x3338
(1) Expecting proxy response no later than 29.999813 seconds from now
(0) Cleaning up request packet ID 37 with timestamp +4
(2) Received Access-Request Id 46 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1812 length 195
(2) Framed-Protocol = PPP
(2) User-Name = "ctest at test"
(2) User-Password = "12312312"
(2) Calling-Station-Id = "GPN02013_testing"
(2) NAS-Port-Type = Ethernet
(2) NAS-Port = 134218230
(2) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(2) Service-Type = Framed-User
(2) NAS-IP-Address = zz.zz.zz.zz
(2) Acct-Session-Id = "0/1/0/502_0012FC88"
(2) NAS-Identifier = "bbkrt1"
(2) # Executing section authorize from file /etc/raddb/sites-enabled/default
(2) authorize {
(2) preprocess: hints: Matched DEFAULT at 64
(2) [preprocess] = ok
(2) suffix: Checking for suffix after "@"
(2) suffix: Looking up realm "test" for User-Name = "ctest at test"
(2) suffix: Found realm "test"
(2) suffix: Adding Stripped-User-Name = "ctest"
(2) suffix: Adding Realm = "test"
(2) suffix: Authentication realm is LOCAL
(2) [suffix] = ok
(2) files: users: Matched entry DEFAULT at line 80
(2) files: EXPAND /etc/raddb/custom_scripts/access.pl %{User-Name} %{NAS-IP-Address} %{NAS-Port} %{NAS-Port-Type} %{Cisco-AVPair[0]}
(2) files: --> /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet
(2) [files] = ok
rlm_ldap (ldap): Reserved connection (2)
(2) ldap: EXPAND (uid=%{Stripped-User-Name})
(2) ldap: --> (uid=ctest)
(2) ldap: Performing search in "ou=people,dc=netnet,dc=net" with filter "(uid=ctest)", scope "sub"
(2) ldap: Waiting for search result...
ber_get_next failed.
rlm_ldap (ldap): Reconnecting (2)
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
(2) ldap: WARNING: Search failed: Can't contact LDAP server. testt new socket, retrying...
(2) ldap: Waiting for search result...
(2) ldap: User object found at DN "uid=ctest,ou=People,dc=netnet,dc=net"
(2) ldap: Processing user attributes
(2) ldap: control:Password-With-Header += '{MD5}GBRn436gerteg39MIFptA=='
rlm_ldap (ldap): Released connection (2)
Need more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (6), 1 of 26 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): Closing expired connection (5) - Hit idle_timeout limit
rlm_ldap (ldap): Closing expired connection (4) - Hit idle_timeout limit
rlm_ldap (ldap): Closing expired connection (3) - Hit idle_timeout limit
rlm_ldap (ldap): Closing expired connection (1) - Hit idle_timeout limit
rlm_ldap (ldap): You probably need to lower "min"
rlm_ldap (ldap): Closing expired connection (0) - Hit idle_timeout limit
(2) [ldap] = updated
(2) [expiration] = noop
(2) [logintime] = noop
(2) pap: Converted: &control:Password-With-Header -> &control:MD5-Password
(2) pap: Removing &control:Password-With-Header
(2) pap: Normalizing MD5-Password from base64 encoding, 24 bytes -> 16 bytes
(2) pap: WARNING: Auth-Type already set. Not setting to PAP
(2) [pap] = noop
(2) } # authorize = updated
(2) Found Auth-Type = LDAP
(2) # Executing group from file /etc/raddb/sites-enabled/default
(2) Auth-Type LDAP {
rlm_ldap (ldap): Reserved connection (2)
(2) ldap: Login attempt by "ctest"
(2) ldap: Using user DN from request "uid=ctest,ou=People,dc=netnet,dc=net"
(2) ldap: Waiting for bind result...
(2) ldap: Bind successful
(2) ldap: Bind as user "uid=ctest,ou=People,dc=netnet,dc=net" was successful
rlm_ldap (ldap): Released connection (2)
(2) [ldap] = ok
(2) } # Auth-Type LDAP = ok
(2) # Executing section post-auth from file /etc/raddb/sites-enabled/default
(2) post-auth {
(2) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) {
(2) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) -> FALSE
(2) update {
(2) No attributes updated for RHS &session-state:
(2) } # update = noop
(2) exec: Executing: /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet :
(2) exec: Program returned code (0) and output 'Framed-IP-Netmask = 255.255.255.255, Framed-MTU = 1492, Service-Type = Framed-User, Framed-Protocol = PPP, Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx", Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227", Cisco-AVPair += "accounting-list=UAT_TST02", Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"'
(2) exec: Program executed successfully
(2) [exec] = ok
(2) policy remove_reply_message_if_eap {
(2) if (&reply:EAP-Message && &reply:Reply-Message) {
(2) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(2) else {
(2) [noop] = noop
(2) } # else = noop
(2) } # policy remove_reply_message_if_eap = noop
(2) } # post-auth = ok
(2) Sent Access-Accept Id 46 from xx.xx.xx.xx:1812 to zz.zz.zz.zz:21678 length 245
(2) Framed-IP-Netmask = 255.255.255.255
(2) Framed-MTU = 1492
(2) Service-Type = Framed-User
(2) Framed-Protocol = PPP
(2) Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx"
(2) Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227"
(2) Cisco-AVPair += "accounting-list=UAT_TST02"
(2) Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"
(2) Finished request
(3) Received Accounting-Request Id 41 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1813 length 203
(3) Acct-Session-Id = "0/1/0/502_0012FC83"
(3) Framed-Protocol = PPP
(3) Framed-IP-Address = 10.10.10.10
(3) User-Name = "ctest at test"
(3) Acct-Authentic = RADIUS
(3) Acct-Status-Type = Start
(3) Calling-Station-Id = "GPN02013_testing"
(3) NAS-Port-Type = Ethernet
(3) NAS-Port = 134218230
(3) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(3) Service-Type = Framed-User
(3) NAS-IP-Address = zz.zz.zz.zz
(3) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(3) Acct-Delay-Time = 30
(3) # Executing section preacct from file /etc/raddb/sites-enabled/default
(3) preacct {
(3) preprocess: hints: Matched DEFAULT at 64
(3) [preprocess] = ok
(3) policy acct_unique {
(3) update request {
(3) &Tmp-String-9 := "ai:"
(3) } # update request = noop
(3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(3) EXPAND %{hex:&Class}
(3) -->
(3) EXPAND ^%{hex:&Tmp-String-9}
(3) --> ^61693a
(3) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(3) else {
(3) update request {
(3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(3) --> 2b083f411e5bfc3b3baed3d31fe210e0
(3) &Acct-Unique-Session-Id := 2b083f411e5bfc3b3baed3d31fe210e0
(3) } # update request = noop
(3) } # else = noop
(3) } # policy acct_unique = noop
(3) suffix: Checking for suffix after "@"
(3) suffix: Looking up realm "test" for User-Name = "ctest at test"
(3) suffix: Found realm "test"
(3) suffix: Adding Stripped-User-Name = "ctest"
(3) suffix: Adding Realm = "test"
(3) suffix: Proxying request from user ctest to realm test
(3) suffix: Preparing to proxy accounting request to realm "test"
(3) [suffix] = updated
(3) [files] = noop
(3) } # preacct = updated
(3) # Executing section accounting from file /etc/raddb/sites-enabled/default
(3) accounting {
(3) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(3) detail: --> /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(3) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(3) detail: EXPAND %t
(3) detail: --> Tue Oct 11 14:30:29 2022
(3) [detail] = ok
(3) [unix] = ok
(3) sql_local: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(3) sql_local: --> type.start.query
(3) sql_local: Using query template 'query'
rlm_sql (sql_local): Reserved connection (0)
(3) sql_local: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-none}}
(3) sql_local: --> ctest
(3) sql_local: SQL-User-Name set to 'ctest'
(3) sql_local: EXPAND INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL
(3) sql_local: --> INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491399), TO_TIMESTAMP(1665491399), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491399), AcctUpdateTime = TO_TIMESTAMP(1665491399), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
(3) sql_local: Executing query: INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491399), TO_TIMESTAMP(1665491399), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491399), AcctUpdateTime = TO_TIMESTAMP(1665491399), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(3) sql_local: SQL query returned: success
(3) sql_local: 1 record(s) updated
rlm_sql (sql_local): Released connection (0)
Need 1 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_sql (sql_local): Opening additional connection (2), 1 of 30 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=radius host=127.0.0.1 user=radius password=password application_name='FreeRADIUS 3.0.25 - radiusd (sql_local)'
Connected to database 'radius' on '127.0.0.1' server version 100021, protocol version 3, backend PID 61431
rlm_sql (sql_local): You probably need to lower "min"
rlm_sql (sql_local): Closing expired connection (1) - Hit idle_timeout limit
rlm_sql_postgresql: Socket destructor called, closing socket
(3) [sql_local] = ok
(3) sql_remote: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(3) sql_remote: --> type.start.query
(3) sql_remote: Using query template 'query'
rlm_sql (sql_remote): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql_remote): Opening additional connection (1), 1 of 1 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668 application_name='FreeRADIUS 3.0.25 - radiusd (sql_remote)'
===============================================================================================================================================================================================================================
After a few minutes, the below will show and cycle for 3 times then RADIUS fails to start
===============================================================================================================================================================================================================================
rlm_sql_postgresql: Connection failed: could not connect to server: Connection timed out Is the server running on host "tst02corpdb.corp.net" (172.16.82.37) and accepting TCP/IP connections on port 5432?
rlm_sql_postgresql: Socket destructor called, closing socket
rlm_sql (sql_remote): Opening connection failed (1)
(3) [sql_remote] = fail
(3) } # accounting = fail
(3) Starting proxy to home server xx.xx.xx.xx port 1813
(3) server default {
(3) }
(3) Proxying request to home server xx.xx.xx.xx port 1813 timeout 30.000000
(3) Sent Accounting-Request Id 120 from 0.0.0.0:33091 to xx.xx.xx.xx:1813 length 210
(3) Acct-Session-Id = "0/1/0/502_0012FC83"
(3) Framed-Protocol = PPP
(3) Framed-IP-Address = 10.10.10.10
(3) User-Name = "ctest"
(3) Acct-Authentic = RADIUS
(3) Acct-Status-Type = Start
(3) Calling-Station-Id = "GPN02013_testing"
(3) NAS-Port-Type = Ethernet
(3) NAS-Port = 134218230
(3) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(3) Service-Type = Framed-User
(3) NAS-IP-Address = zz.zz.zz.zz
(3) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(3) Acct-Delay-Time = 30
(3) Event-Timestamp = "Oct 11 2022 14:29:59 CEST"
(3) Proxy-State = 0x3431
(3) Expecting proxy response no later than 29.999795 seconds from now
(2) Cleaning up request packet ID 46 with timestamp +132
(1) No proxy response, giving up on request and marking it done
Marking home server xx.xx.xx.xx port 1813 as zombie (it has not responded in 30.000000 seconds).
(1) ERROR: Failing proxied request for user "ctest", due to lack of any response from home server xx.xx.xx.xx port 1813
(1) Clearing existing &reply: attributes
(1) Found Post-Proxy-Type Fail-Accounting
(1) server default {
(1) Post-Proxy-Type sub-section not found. Ignoring.
(1) }
(1) Not sending reply to client.
(1) Finished request
(1) Cleaning up request packet ID 38 with timestamp +4
(4) Received Access-Request Id 50 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1812 length 195
(4) Framed-Protocol = PPP
(4) User-Name = "ctest at test"
(4) User-Password = "12312312"
(4) Calling-Station-Id = "GPN02013_testing"
(4) NAS-Port-Type = Ethernet
(4) NAS-Port = 134218230
(4) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(4) Service-Type = Framed-User
(4) NAS-IP-Address = zz.zz.zz.zz
(4) Acct-Session-Id = "0/1/0/502_0012FC8A"
(4) NAS-Identifier = "bbkrt1"
(4) # Executing section authorize from file /etc/raddb/sites-enabled/default
(4) authorize {
(4) preprocess: hints: Matched DEFAULT at 64
(4) [preprocess] = ok
(4) suffix: Checking for suffix after "@"
(4) suffix: Looking up realm "test" for User-Name = "ctest at test"
(4) suffix: Found realm "test"
(4) suffix: Adding Stripped-User-Name = "ctest"
(4) suffix: Adding Realm = "test"
(4) suffix: Authentication realm is LOCAL
(4) [suffix] = ok
(4) files: users: Matched entry DEFAULT at line 80
(4) files: EXPAND /etc/raddb/custom_scripts/access.pl %{User-Name} %{NAS-IP-Address} %{NAS-Port} %{NAS-Port-Type} %{Cisco-AVPair[0]}
(4) files: --> /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet
(4) [files] = ok
rlm_ldap (ldap): Reserved connection (6)
(4) ldap: EXPAND (uid=%{Stripped-User-Name})
(4) ldap: --> (uid=ctest)
(4) ldap: Performing search in "ou=people,dc=netnet,dc=net" with filter "(uid=ctest)", scope "sub"
(4) ldap: Waiting for search result...
ber_get_next failed.
rlm_ldap (ldap): Reconnecting (6)
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
(4) ldap: WARNING: Search failed: Can't contact LDAP server. testt new socket, retrying...
(4) ldap: Waiting for search result...
(4) ldap: User object found at DN "uid=ctest,ou=People,dc=netnet,dc=net"
(4) ldap: Processing user attributes
(4) ldap: control:Password-With-Header += '{MD5}G232BRnMl43565gg39MIFeeptA=='
rlm_ldap (ldap): Released connection (6)
Need 1 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (7), 1 of 30 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): You probably need to lower "min"
rlm_ldap (ldap): Closing expired connection (2) - Hit idle_timeout limit
(4) [ldap] = updated
(4) [expiration] = noop
(4) [logintime] = noop
(4) pap: Converted: &control:Password-With-Header -> &control:MD5-Password
(4) pap: Removing &control:Password-With-Header
(4) pap: Normalizing MD5-Password from base64 encoding, 24 bytes -> 16 bytes
(4) pap: WARNING: Auth-Type already set. Not setting to PAP
(4) [pap] = noop
(4) } # authorize = updated
(4) Found Auth-Type = LDAP
(4) # Executing group from file /etc/raddb/sites-enabled/default
(4) Auth-Type LDAP {
rlm_ldap (ldap): Reserved connection (6)
(4) ldap: Login attempt by "ctest"
(4) ldap: Using user DN from request "uid=ctest,ou=People,dc=netnet,dc=net"
(4) ldap: Waiting for bind result...
(4) ldap: Bind successful
(4) ldap: Bind as user "uid=ctest,ou=People,dc=netnet,dc=net" was successful
rlm_ldap (ldap): Released connection (6)
(4) [ldap] = ok
(4) } # Auth-Type LDAP = ok
(4) # Executing section post-auth from file /etc/raddb/sites-enabled/default
(4) post-auth {
(4) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) {
(4) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) -> FALSE
(4) update {
(4) No attributes updated for RHS &session-state:
(4) } # update = noop
(4) exec: Executing: /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet :
(4) exec: Program returned code (0) and output 'Framed-IP-Netmask = 255.255.255.255, Framed-MTU = 1492, Service-Type = Framed-User, Framed-Protocol = PPP, Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx", Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227", Cisco-AVPair += "accounting-list=UAT_TST02", Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"'
(4) exec: Program executed successfully
(4) [exec] = ok
(4) policy remove_reply_message_if_eap {
(4) if (&reply:EAP-Message && &reply:Reply-Message) {
(4) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(4) else {
(4) [noop] = noop
(4) } # else = noop
(4) } # policy remove_reply_message_if_eap = noop
(4) } # post-auth = ok
(4) Sent Access-Accept Id 50 from xx.xx.xx.xx:1812 to zz.zz.zz.zz:21678 length 245
(4) Framed-IP-Netmask = 255.255.255.255
(4) Framed-MTU = 1492
(4) Service-Type = Framed-User
(4) Framed-Protocol = PPP
(4) Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx"
(4) Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227"
(4) Cisco-AVPair += "accounting-list=UAT_TST02"
(4) Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"
(4) Finished request
(5) Received Accounting-Request Id 44 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1813 length 239
(5) Acct-Session-Id = "0/1/0/502_0012FC83"
(5) Framed-Protocol = PPP
(5) Framed-IP-Address = 10.10.10.10
(5) User-Name = "ctest at test"
(5) Acct-Authentic = RADIUS
(5) Acct-Session-Time = 59
(5) Acct-Input-Octets = 294
(5) Acct-Output-Octets = 336
(5) Acct-Input-Packets = 12
(5) Acct-Output-Packets = 13
(5) Acct-Terminate-Cause = Admin-Reset
(5) Acct-Status-Type = Stop
(5) Calling-Station-Id = "GPN02013_testing"
(5) NAS-Port-Type = Ethernet
(5) NAS-Port = 134218230
(5) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(5) Service-Type = Framed-User
(5) NAS-IP-Address = zz.zz.zz.zz
(5) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(5) Acct-Delay-Time = 0
(5) # Executing section preacct from file /etc/raddb/sites-enabled/default
(5) preacct {
(5) preprocess: hints: Matched DEFAULT at 64
(5) [preprocess] = ok
(5) policy acct_unique {
(5) update request {
(5) &Tmp-String-9 := "ai:"
(5) } # update request = noop
(5) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(5) EXPAND %{hex:&Class}
(5) -->
(5) EXPAND ^%{hex:&Tmp-String-9}
(5) --> ^61693a
(5) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(5) else {
(5) update request {
(5) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(5) --> 2b083f411e5bfc3b3baed3d31fe210e0
(5) &Acct-Unique-Session-Id := 2b083f411e5bfc3b3baed3d31fe210e0
(5) } # update request = noop
(5) } # else = noop
(5) } # policy acct_unique = noop
(5) suffix: Checking for suffix after "@"
(5) suffix: Looking up realm "test" for User-Name = "ctest at test"
(5) suffix: Found realm "test"
(5) suffix: Adding Stripped-User-Name = "ctest"
(5) suffix: Adding Realm = "test"
(5) suffix: Proxying request from user ctest to realm test
(5) suffix: Preparing to proxy accounting request to realm "test"
(5) [suffix] = updated
(5) [files] = noop
(5) } # preacct = updated
(5) # Executing section accounting from file /etc/raddb/sites-enabled/default
(5) accounting {
(5) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(5) detail: --> /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(5) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(5) detail: EXPAND %t
(5) detail: --> Tue Oct 11 14:32:40 2022
(5) [detail] = ok
(5) [unix] = ok
(5) sql_local: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(5) sql_local: --> type.stop.query
(5) sql_local: Using query template 'query'
rlm_sql (sql_local): Reserved connection (0)
(5) sql_local: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-none}}
(5) sql_local: --> ctest
(5) sql_local: SQL-User-Name set to 'ctest'
(5) sql_local: EXPAND UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctSessionTime = COALESCE(%{%{Acct-Session-Time}:-NULL}, (%{integer:Event-Timestamp} - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('%{%{Acct-Input-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Input-Octets}:-0}'::bigint), AcctOutputOctets = (('%{%{Acct-Output-Gigawords}:-0}'::bigint << 32) + '%{%{Acct-Output-Octets}:-0}'::bigint), AcctTerminateCause = '%{Acct-Terminate-Cause}', FramedIPAddress = NULLIF('%{Framed-IP-Address}', '')::inet, FramedIPv6Address = NULLIF('%{Framed-IPv6-Address}', '')::inet, FramedIPv6Prefix = NULLIF('%{Framed-IPv6-Prefix}', '')::inet, FramedInterfaceId = NULLIF('%{Framed-Interface-Id}', ''), DelegatedIPv6Prefix = NULLIF('%{Delegated-IPv6-Prefix}', '')::inet, ConnectInfo_stop = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}' AND AcctStopTime IS NULL
(5) sql_local: --> UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(1665491560), AcctUpdateTime = TO_TIMESTAMP(1665491560), AcctSessionTime = COALESCE(59, (1665491560 - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('0'::bigint << 32) + '294'::bigint), AcctOutputOctets = (('0'::bigint << 32) + '336'::bigint), AcctTerminateCause = 'Admin-Reset', FramedIPAddress = NULLIF('10.10.10.10', '')::inet, FramedIPv6Address = NULLIF('', '')::inet, FramedIPv6Prefix = NULLIF('', '')::inet, FramedInterfaceId = NULLIF('', ''), DelegatedIPv6Prefix = NULLIF('', '')::inet, ConnectInfo_stop = '' WHERE AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND AcctStopTime IS NULL
(5) sql_local: Executing query: UPDATE radacct SET AcctStopTime = TO_TIMESTAMP(1665491560), AcctUpdateTime = TO_TIMESTAMP(1665491560), AcctSessionTime = COALESCE(59, (1665491560 - EXTRACT(EPOCH FROM(AcctStartTime)))), AcctInputOctets = (('0'::bigint << 32) + '294'::bigint), AcctOutputOctets = (('0'::bigint << 32) + '336'::bigint), AcctTerminateCause = 'Admin-Reset', FramedIPAddress = NULLIF('10.10.10.10', '')::inet, FramedIPv6Address = NULLIF('', '')::inet, FramedIPv6Prefix = NULLIF('', '')::inet, FramedInterfaceId = NULLIF('', ''), DelegatedIPv6Prefix = NULLIF('', '')::inet, ConnectInfo_stop = '' WHERE AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND AcctStopTime IS NULL
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(5) sql_local: SQL query returned: success
(5) sql_local: 1 record(s) updated
rlm_sql (sql_local): Released connection (0)
Need 1 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_sql (sql_local): Opening additional connection (3), 1 of 30 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=radius host=127.0.0.1 user=radius password=password application_name='FreeRADIUS 3.0.25 - radiusd (sql_local)'
Connected to database 'radius' on '127.0.0.1' server version 100021, protocol version 3, backend PID 61442
rlm_sql (sql_local): You probably need to lower "min"
rlm_sql (sql_local): Closing expired connection (2) - Hit idle_timeout limit
rlm_sql_postgresql: Socket destructor called, closing socket
(5) [sql_local] = ok
(5) sql_remote: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(5) sql_remote: --> type.stop.query
(5) sql_remote: Using query template 'query'
rlm_sql (sql_remote): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql_remote): Opening additional connection (2), 1 of 1 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668 application_name='FreeRADIUS 3.0.25 - radiusd (sql_remote)'
rlm_sql_postgresql: Connection failed: could not connect to server: Connection timed out Is the server running on host "tst02corpdb.corp.net" (172.16.82.37) and accepting TCP/IP connections on port 5432?
rlm_sql_postgresql: Socket destructor called, closing socket
rlm_sql (sql_remote): Opening connection failed (2)
(5) [sql_remote] = fail
(5) } # accounting = fail
(5) Starting proxy to home server xx.xx.xx.xx port 1813
(5) server default {
(5) }
(5) Proxying request to home server xx.xx.xx.xx port 1813 timeout 30.000000
(5) Sent Accounting-Request Id 24 from 0.0.0.0:33091 to xx.xx.xx.xx:1813 length 246
(5) Acct-Session-Id = "0/1/0/502_0012FC83"
(5) Framed-Protocol = PPP
(5) Framed-IP-Address = 10.10.10.10
(5) User-Name = "ctest"
(5) Acct-Authentic = RADIUS
(5) Acct-Session-Time = 59
(5) Acct-Input-Octets = 294
(5) Acct-Output-Octets = 336
(5) Acct-Input-Packets = 12
(5) Acct-Output-Packets = 13
(5) Acct-Terminate-Cause = Admin-Reset
(5) Acct-Status-Type = Stop
(5) Calling-Station-Id = "GPN02013_testing"
(5) NAS-Port-Type = Ethernet
(5) NAS-Port = 134218230
(5) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(5) Service-Type = Framed-User
(5) NAS-IP-Address = zz.zz.zz.zz
(5) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(5) Acct-Delay-Time = 0
(5) Event-Timestamp = "Oct 11 2022 14:32:40 CEST"
(5) Proxy-State = 0x3434
No outstanding request was found for Accounting-Response packet from host xx.xx.xx.xx port 1813 - ID 255
(5) Expecting proxy response no later than 29.999456 seconds from now
(4) Cleaning up request packet ID 50 with timestamp +264
(3) No proxy response, giving up on request and marking it done
(3) ERROR: Failing proxied request for user "ctest", due to lack of any response from home server xx.xx.xx.xx port 1813
(3) Clearing existing &reply: attributes
(3) Found Post-Proxy-Type Fail-Accounting
(3) server default {
(3) Post-Proxy-Type sub-section not found. Ignoring.
(3) }
(3) Not sending reply to client.
(3) Finished request
(3) Cleaning up request packet ID 41 with timestamp +133
PING: Zombie period is over for home server proxy
Marking home server xx.xx.xx.xx port 1813 as dead.
PING: Reviving home server proxyin 120 seconds
(6) Received Access-Request Id 54 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1812 length 195
(6) Framed-Protocol = PPP
(6) User-Name = "ctest at test"
(6) User-Password = "12312312"
(6) Calling-Station-Id = "GPN02013_testing"
(6) NAS-Port-Type = Ethernet
(6) NAS-Port = 134218230
(6) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(6) Service-Type = Framed-User
(6) NAS-IP-Address = zz.zz.zz.zz
(6) Acct-Session-Id = "0/1/0/502_0012FC8E"
(6) NAS-Identifier = "bbkrt1"
(6) # Executing section authorize from file /etc/raddb/sites-enabled/default
(6) authorize {
(6) preprocess: hints: Matched DEFAULT at 64
(6) [preprocess] = ok
(6) suffix: Checking for suffix after "@"
(6) suffix: Looking up realm "test" for User-Name = "ctest at test"
(6) suffix: Found realm "test"
(6) suffix: Adding Stripped-User-Name = "ctest"
(6) suffix: Adding Realm = "test"
(6) suffix: Authentication realm is LOCAL
(6) [suffix] = ok
(6) files: users: Matched entry DEFAULT at line 80
(6) files: EXPAND /etc/raddb/custom_scripts/access.pl %{User-Name} %{NAS-IP-Address} %{NAS-Port} %{NAS-Port-Type} %{Cisco-AVPair[0]}
(6) files: --> /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet
(6) [files] = ok
rlm_ldap (ldap): Reserved connection (7)
(6) ldap: EXPAND (uid=%{Stripped-User-Name})
(6) ldap: --> (uid=ctest)
(6) ldap: Performing search in "ou=people,dc=netnet,dc=net" with filter "(uid=ctest)", scope "sub"
(6) ldap: Waiting for search result...
rlm_ldap (ldap): Reconnecting (7)
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
(6) ldap: WARNING: Search failed: Can't contact LDAP server. testt new socket, retrying...
(6) ldap: Waiting for search result...
(6) ldap: User object found at DN "uid=ctest,ou=People,dc=netnet,dc=net"
(6) ldap: Processing user attributes
(6) ldap: control:Password-With-Header += '{MD5}GBRnMlwaST+2lP39MIFptA=='
rlm_ldap (ldap): Released connection (7)
Need 1 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (8), 1 of 30 pending slots used
rlm_ldap (ldap): Connecting to ldap://localhost:389
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
rlm_ldap (ldap): You probably need to lower "min"
rlm_ldap (ldap): Closing expired connection (6) - Hit idle_timeout limit
(6) [ldap] = updated
(6) [expiration] = noop
(6) [logintime] = noop
(6) pap: Converted: &control:Password-With-Header -> &control:MD5-Password
(6) pap: Removing &control:Password-With-Header
(6) pap: Normalizing MD5-Password from base64 encoding, 24 bytes -> 16 bytes
(6) pap: WARNING: Auth-Type already set. Not setting to PAP
(6) [pap] = noop
(6) } # authorize = updated
(6) Found Auth-Type = LDAP
(6) # Executing group from file /etc/raddb/sites-enabled/default
(6) Auth-Type LDAP {
rlm_ldap (ldap): Reserved connection (7)
(6) ldap: Login attempt by "ctest"
(6) ldap: Using user DN from request "uid=ctest,ou=People,dc=netnet,dc=net"
(6) ldap: Waiting for bind result...
(6) ldap: Bind successful
(6) ldap: Bind as user "uid=ctest,ou=People,dc=netnet,dc=net" was successful
rlm_ldap (ldap): Released connection (7)
(6) [ldap] = ok
(6) } # Auth-Type LDAP = ok
(6) # Executing section post-auth from file /etc/raddb/sites-enabled/default
(6) post-auth {
(6) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) {
(6) if (session-state:User-Name && reply:User-Name && request:User-Name && (reply:User-Name == request:User-Name)) -> FALSE
(6) update {
(6) No attributes updated for RHS &session-state:
(6) } # update = noop
(6) exec: Executing: /etc/raddb/custom_scripts/access.pl ctest at test zz.zz.zz.zz 134218230 Ethernet :
(6) exec: Program returned code (0) and output 'Framed-IP-Netmask = 255.255.255.255, Framed-MTU = 1492, Service-Type = Framed-User, Framed-Protocol = PPP, Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx", Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227", Cisco-AVPair += "accounting-list=UAT_TST02", Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"'
(6) exec: Program executed successfully
(6) [exec] = ok
(6) policy remove_reply_message_if_eap {
(6) if (&reply:EAP-Message && &reply:Reply-Message) {
(6) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(6) else {
(6) [noop] = noop
(6) } # else = noop
(6) } # policy remove_reply_message_if_eap = noop
(6) } # post-auth = ok
(6) Sent Access-Accept Id 54 from xx.xx.xx.xx:1812 to zz.zz.zz.zz:21678 length 245
(6) Framed-IP-Netmask = 255.255.255.255
(6) Framed-MTU = 1492
(6) Service-Type = Framed-User
(6) Framed-Protocol = PPP
(6) Cisco-AVPair = "ip:dns-servers=xx.xx.xx.xx xx.xx.xx.xx"
(6) Cisco-AVPair += "lcp:interface-config=ip unnumbered Loopback227"
(6) Cisco-AVPair += "accounting-list=UAT_TST02"
(6) Cisco-AVPair += "lcp:interface-config=peer default ip address pool netnet"
(6) Finished request
(7) Received Accounting-Request Id 45 from zz.zz.zz.zz:21678 to xx.xx.xx.xx:1813 length 203
(7) Acct-Session-Id = "0/1/0/502_0012FC83"
(7) Framed-Protocol = PPP
(7) Framed-IP-Address = 10.10.10.10
(7) User-Name = "ctest at test"
(7) Acct-Authentic = RADIUS
(7) Acct-Status-Type = Start
(7) Calling-Station-Id = "GPN02013_testing"
(7) NAS-Port-Type = Ethernet
(7) NAS-Port = 134218230
(7) NAS-Port-Id = "SL-PO-12 eth 1/1/10/07/18/00000/1/2:2"
(7) Service-Type = Framed-User
(7) NAS-IP-Address = zz.zz.zz.zz
(7) PMIP6-Home-HN-Prefix = 4335:4343:3744::/51
(7) Acct-Delay-Time = 60
(7) # Executing section preacct from file /etc/raddb/sites-enabled/default
(7) preacct {
(7) preprocess: hints: Matched DEFAULT at 64
(7) [preprocess] = ok
(7) policy acct_unique {
(7) update request {
(7) &Tmp-String-9 := "ai:"
(7) } # update request = noop
(7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(7) EXPAND %{hex:&Class}
(7) -->
(7) EXPAND ^%{hex:&Tmp-String-9}
(7) --> ^61693a
(7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(7) else {
(7) update request {
(7) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(7) --> 2b083f411e5bfc3b3baed3d31fe210e0
(7) &Acct-Unique-Session-Id := 2b083f411e5bfc3b3baed3d31fe210e0
(7) } # update request = noop
(7) } # else = noop
(7) } # policy acct_unique = noop
(7) suffix: Checking for suffix after "@"
(7) suffix: Looking up realm "test" for User-Name = "ctest at test"
(7) suffix: Found realm "test"
(7) suffix: Adding Stripped-User-Name = "ctest"
(7) suffix: Adding Realm = "test"
(7) suffix: Proxying request from user ctest to realm test
(7) suffix: Preparing to proxy accounting request to realm "test"
(7) [suffix] = updated
(7) [files] = noop
(7) } # preacct = updated
(7) # Executing section accounting from file /etc/raddb/sites-enabled/default
(7) accounting {
(7) detail: EXPAND /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(7) detail: --> /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(7) detail: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/zz.zz.zz.zz/detail-20221011
(7) detail: EXPAND %t
(7) detail: --> Tue Oct 11 14:34:51 2022
(7) [detail] = ok
(7) [unix] = ok
(7) sql_local: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(7) sql_local: --> type.start.query
(7) sql_local: Using query template 'query'
rlm_sql (sql_local): Reserved connection (0)
(7) sql_local: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-none}}
(7) sql_local: --> ctest
(7) sql_local: SQL-User-Name set to 'ctest'
(7) sql_local: EXPAND INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}', NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}', TO_TIMESTAMP(%{integer:Event-Timestamp}), TO_TIMESTAMP(%{integer:Event-Timestamp}), NULL, 0, '%{Acct-Authentic}', '%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}', '%{Calling-Station-Id}', NULL, '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, NULLIF('%{Framed-IPv6-Address}', '')::inet, NULLIF('%{Framed-IPv6-Prefix}', '')::inet, NULLIF('%{Framed-Interface-Id}', ''), NULLIF('%{Delegated-IPv6-Prefix}', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE radacct.AcctUniqueId = '%{Acct-Unique-Session-Id}' AND radacct.AcctStopTime IS NULL
(7) sql_local: --> INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491631), TO_TIMESTAMP(1665491631), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491631), AcctUpdateTime = TO_TIMESTAMP(1665491631), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
(7) sql_local: Executing query: INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctUpdateTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_Stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIpAddress, FramedIpv6Address, FramedIpv6Prefix, FramedInterfaceId, DelegatedIpv6Prefix) VALUES('0/1/0/502_0012FC83', '2b083f411e5bfc3b3baed3d31fe210e0', 'ctest', NULLIF('test', ''), 'zz.zz.zz.zz', NULLIF('SL-PO-12 eth 1/1/10/07/18/00000/1/2:2', ''), 'Ethernet', TO_TIMESTAMP(1665491631), TO_TIMESTAMP(1665491631), NULL, 0, 'RADIUS', '', NULL, 0, 0, '', 'GPN02013_testing', NULL, 'Framed-User', 'PPP', NULLIF('10.10.10.10', '')::inet, NULLIF('', '')::inet, NULLIF('', '')::inet, NULLIF('', ''), NULLIF('', '')::inet) ON CONFLICT (AcctUniqueId) DO UPDATE SET AcctStartTime = TO_TIMESTAMP(1665491631), AcctUpdateTime = TO_TIMESTAMP(1665491631), ConnectInfo_start = '' WHERE radacct.AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0' AND radacct.AcctStopTime IS NULL
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
(7) sql_local: SQL query returned: success
(7) sql_local: 0 record(s) updated
(7) sql_local: Trying next query...
(7) sql_local: EXPAND UPDATE radacct SET AcctStartTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), AcctUpdateTime = TO_TIMESTAMP(%{integer:Event-Timestamp}), ConnectInfo_start = '%{Connect-Info}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
(7) sql_local: --> UPDATE radacct SET AcctStartTime = TO_TIMESTAMP(1665491631), AcctUpdateTime = TO_TIMESTAMP(1665491631), ConnectInfo_start = '' WHERE AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0'
(7) sql_local: Executing query: UPDATE radacct SET AcctStartTime = TO_TIMESTAMP(1665491631), AcctUpdateTime = TO_TIMESTAMP(1665491631), ConnectInfo_start = '' WHERE AcctUniqueId = '2b083f411e5bfc3b3baed3d31fe210e0'
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(7) sql_local: SQL query returned: success
(7) sql_local: 1 record(s) updated
rlm_sql (sql_local): Released connection (0)
Need 1 more connections to reach min connections (3)
Need more connections to reach 10 spares
rlm_sql (sql_local): Opening additional connection (4), 1 of 30 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=radius host=127.0.0.1 user=radius password=password application_name='FreeRADIUS 3.0.25 - radiusd (sql_local)'
Connected to database 'radius' on '127.0.0.1' server version 100021, protocol version 3, backend PID 61454
rlm_sql (sql_local): You probably need to lower "min"
rlm_sql (sql_local): Closing expired connection (3) - Hit idle_timeout limit
rlm_sql_postgresql: Socket destructor called, closing socket
(7) [sql_local] = ok
(7) sql_remote: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(7) sql_remote: --> type.start.query
(7) sql_remote: Using query template 'query'
rlm_sql (sql_remote): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql_remote): Opening additional connection (3), 1 of 1 pending slots used
rlm_sql_postgresql: Connecting using parameters: dbname=tst02bbradius host=tst02corpdb.corp.net user=tst02bbradiususer password=asdfghjklkjhgf668 application_name='FreeRADIUS 3.0.25 - radiusd (sql_remote)'
^C[root at TST02_RADAUTH01_PG_COMPILE ~]#
More information about the Freeradius-Users
mailing list