No More Handles Error after approximate 5500 transactions

22 Apr 2021

      Hello all,

I am migrating some radius servers from RHEL6 with freeradius 3.0.16 to 
RHEL7 with freeradius 3.0.21.  Our backend database is db2 using the 
rlm_sql_db2.so driver.   On the RHEL6 nodes we were using the pre-built 
RedHat RPM packages for the freeradius and the rlm_sql_db2-3.0.0.so that 
came from an old installation but I'm not certain of its origins.  With 
the move the RHEL7 I tried using the RedHat RPMs with the existing 
rlm_sql_db2-3.0.0.so but that failed miserably as expected.  I built the 
rlm_sql_db2-3.0.0.so from source and tried that with the pre-built RPMs 
and that also failed miserably.  Now I'm running with freeradius that was 
built from source code on a RHEL7 box.  Freeradius and the rlm_sql_db2.so 
driver.  This combination works and packets seem to run fine, db2 tables 
are updated as expected.  Devices accepted/rejected as expected.

However, when I run a load of test traffic through the radius devices I am 
getting db2 client errors after about 5500 transactions.  The specific 
error message I see in the radius logs is this:

Tue Apr 20 18:37:46 2021 : ERROR: (17291)         ERROR: rlm_sql_db2: 
HY014: [IBM][CLI Driver] CLI0129E  An attempt to allocate a handle failed 
because there are no more handles to allocate. SQLSTATE=HY014

Below is the debug log with a few transactions that were fine at the 
beginning and then I cut out a lot of the log just because it was so 
large, and a few transactions at the end after they started failing.  If 
there is a better way to include the full log please let me know.  It is 
quite large since it takes a while for the problems to begin.

Thanks in advance for any help,
Michael

FreeRADIUS Version 3.0.21
Copyright (C) 1999-2019 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/share/freeradius/dictionary
including dictionary file /usr/share/freeradius/dictionary.dhcp
including dictionary file /usr/share/freeradius/dictionary.vqp
including dictionary file /etc/edr_raddb/dictionary
including configuration file /etc/edr_raddb/radiusd.conf
including configuration file /etc/edr_raddb/proxy.conf
including configuration file /etc/edr_raddb/clients.conf
including files in directory /etc/edr_raddb/mods-enabled/
including configuration file /etc/edr_raddb/mods-enabled/files
including configuration file /etc/edr_raddb/mods-enabled/sradutmp
including configuration file /etc/edr_raddb/mods-enabled/radutmp
including configuration file /etc/edr_raddb/mods-enabled/echo
including configuration file /etc/edr_raddb/mods-enabled/expr
including configuration file /etc/edr_raddb/mods-enabled/preprocess
including configuration file /etc/edr_raddb/mods-enabled/soh
including configuration file /etc/edr_raddb/mods-enabled/detail
including configuration file /etc/edr_raddb/mods-enabled/unpack
including configuration file /etc/edr_raddb/mods-enabled/replicate
including configuration file /etc/edr_raddb/mods-enabled/mschap
including configuration file /etc/edr_raddb/mods-enabled/digest
including configuration file /etc/edr_raddb/mods-enabled/attr_filter
including configuration file /etc/edr_raddb/mods-enabled/sql
including configuration file 
/etc/edr_raddb/mods-config/sql/main/db2/queries.conf
including configuration file /etc/edr_raddb/mods-enabled/detail.log
including configuration file /etc/edr_raddb/mods-enabled/linelog
including configuration file /etc/edr_raddb/mods-enabled/logintime
including configuration file /etc/edr_raddb/mods-enabled/expiration
including configuration file /etc/edr_raddb/mods-enabled/unix
including configuration file /etc/edr_raddb/mods-enabled/date
including configuration file /etc/edr_raddb/mods-enabled/chap
including configuration file /etc/edr_raddb/mods-enabled/exec
including configuration file /etc/edr_raddb/mods-enabled/utf8
including configuration file /etc/edr_raddb/mods-enabled/ntlm_auth
including configuration file /etc/edr_raddb/mods-enabled/passwd
including configuration file /etc/edr_raddb/mods-enabled/cache_eap
including configuration file /etc/edr_raddb/mods-enabled/realm
including configuration file /etc/edr_raddb/mods-enabled/dynamic_clients
including configuration file /etc/edr_raddb/mods-enabled/pap
including configuration file /etc/edr_raddb/mods-enabled/always
including files in directory /etc/edr_raddb/policy.d/
including configuration file /etc/edr_raddb/policy.d/accounting
including configuration file /etc/edr_raddb/policy.d/dhcp
including configuration file /etc/edr_raddb/policy.d/edr
including configuration file /etc/edr_raddb/policy.d/debug
including configuration file /etc/edr_raddb/policy.d/filter
including configuration file /etc/edr_raddb/policy.d/operator-name
including configuration file /etc/edr_raddb/policy.d/eap
including configuration file /etc/edr_raddb/policy.d/cui
including configuration file /etc/edr_raddb/policy.d/rfc7542
including configuration file /etc/edr_raddb/policy.d/abfab-tr
including configuration file /etc/edr_raddb/policy.d/moonshot-targeted-ids
including configuration file /etc/edr_raddb/policy.d/canonicalization
including configuration file /etc/edr_raddb/policy.d/control
including files in directory /etc/edr_raddb/sites-enabled/
including configuration file /etc/edr_raddb/sites-enabled/default
main {
 security {
        user = "radiusd"
        group = "radiusd"
        allow_core_dumps = no
 }
        name = "radiusd"
        prefix = "/usr"
        localstatedir = "/var/log"
        logdir = "/var/log/radiusd"
        run_dir = "/var/log/run/radiusd"
}
main {
        name = "radiusd"
        prefix = "/usr"
        localstatedir = "/var/log"
        sbindir = "/usr/sbin"
        logdir = "/var/log/radiusd"
        run_dir = "/var/log/run/radiusd"
        libdir = "/usr/lib64/freeradius"
        radacctdir = "/var/log/radiusd/radacct"
        hostname_lookups = no
        max_request_time = 5
        cleanup_delay = 2
        max_requests = 16384
        pidfile = "/var/log/radiusd/radiusd.pid"
        checkrad = "/usr/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = yes
        auth_badpass = yes
        auth_goodpass = yes
        msg_badpass = "%{&reply:Reply-Message}"
        msg_goodpass = "%{&reply:Reply-Message}"
        colourise = yes
        msg_denied = "You are already logged in - access denied"
 }
 resources {
 }
 security {
        max_attributes = 200
        reject_delay = 0.000000
        status_server = yes
        allow_vulnerable_openssl = "CVE-2016-6304"
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 home_server localhost {
        ipaddr = 127.0.0.1
        port = 1812
        type = "auth"
        secret = <<< secret >>>
        response_window = 20.000000
        response_timeouts = 1
        max_outstanding = 65536
        zombie_period = 40
        status_check = "status-server"
        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 = 20.000000", forcing to "response_window = 
5.000000"
 home_server_pool my_auth_failover {
        type = fail-over
        home_server = localhost
 }
 realm example.com {
        auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client localhost {
        ipaddr = 127.0.0.1
        require_message_authenticator = no
        secret = <<< secret >>>
  limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
  }
 }
 client IBM-10client {
        ipaddr = 10.0.0.0
        netmask = 8
        require_message_authenticator = no
        secret = <<< secret >>>
  limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
  }
 }
 client IBM-9client {
        ipaddr = 9.0.0.0
        netmask = 8
        require_message_authenticator = no
        secret = <<< secret >>>
  limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
  }
 }
Debugger not attached
systemd watchdog is disabled
radiusd: #### Instantiating modules ####
 modules {
  # Loaded module rlm_files
  # Loading module "files" from file /etc/edr_raddb/mods-enabled/files
  files {
        filename = "/etc/edr_raddb/mods-config/files/authorize"
        acctusersfile = "/etc/edr_raddb/mods-config/files/accounting"
        preproxy_usersfile = "/etc/edr_raddb/mods-config/files/pre-proxy"
  }
  # Loaded module rlm_radutmp
  # Loading module "sradutmp" from file 
/etc/edr_raddb/mods-enabled/sradutmp
  radutmp sradutmp {
        filename = "/var/log/radiusd/sradutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        permissions = 420
        caller_id = no
  }
  # Loading module "radutmp" from file /etc/edr_raddb/mods-enabled/radutmp
  radutmp {
        filename = "/var/log/radiusd/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        permissions = 384
        caller_id = yes
  }
  # Loaded module rlm_exec
  # Loading module "echo" from file /etc/edr_raddb/mods-enabled/echo
  exec echo {
        wait = yes
        program = "/bin/echo %{User-Name}"
        input_pairs = "request"
        output_pairs = "reply"
        shell_escape = yes
        timeout = 5
  }
  # Loaded module rlm_expr
  # Loading module "expr" from file /etc/edr_raddb/mods-enabled/expr
  expr {
        safe_characters = 
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: 
/äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
  }
  # Loaded module rlm_preprocess
  # Loading module "preprocess" from file 
/etc/edr_raddb/mods-enabled/preprocess
  preprocess {
        huntgroups = "/etc/edr_raddb/mods-config/preprocess/huntgroups"
        hints = "/etc/edr_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_soh
  # Loading module "soh" from file /etc/edr_raddb/mods-enabled/soh
  soh {
        dhcp = yes
  }
  # Loaded module rlm_detail
  # Loading module "detail" from file /etc/edr_raddb/mods-enabled/detail
  detail {
        filename = 
"/var/log/radiusd/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
  }
  # Loaded module rlm_unpack
  # Loading module "unpack" from file /etc/edr_raddb/mods-enabled/unpack
  # Loaded module rlm_replicate
  # Loading module "replicate" from file 
/etc/edr_raddb/mods-enabled/replicate
  # Loaded module rlm_mschap
  # Loading module "mschap" from file /etc/edr_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
  }
  # Loaded module rlm_digest
  # Loading module "digest" from file /etc/edr_raddb/mods-enabled/digest
  # Loaded module rlm_attr_filter
  # Loading module "attr_filter.post-proxy" from file 
/etc/edr_raddb/mods-enabled/attr_filter
  attr_filter attr_filter.post-proxy {
        filename = "/etc/edr_raddb/mods-config/attr_filter/post-proxy"
        key = "%{Realm}"
        relaxed = no
  }
  # Loading module "attr_filter.pre-proxy" from file 
/etc/edr_raddb/mods-enabled/attr_filter
  attr_filter attr_filter.pre-proxy {
        filename = "/etc/edr_raddb/mods-config/attr_filter/pre-proxy"
        key = "%{Realm}"
        relaxed = no
  }
  # Loading module "attr_filter.access_reject" from file 
/etc/edr_raddb/mods-enabled/attr_filter
  attr_filter attr_filter.access_reject {
        filename = "/etc/edr_raddb/mods-config/attr_filter/access_reject"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loading module "attr_filter.access_challenge" from file 
/etc/edr_raddb/mods-enabled/attr_filter
  attr_filter attr_filter.access_challenge {
        filename = 
"/etc/edr_raddb/mods-config/attr_filter/access_challenge"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loading module "attr_filter.accounting_response" from file 
/etc/edr_raddb/mods-enabled/attr_filter
  attr_filter attr_filter.accounting_response {
        filename = 
"/etc/edr_raddb/mods-config/attr_filter/accounting_response"
        key = "%{User-Name}"
        relaxed = no
  }
  # Loaded module rlm_sql
  # Loading module "sql" from file /etc/edr_raddb/mods-enabled/sql
  sql {
        driver = "rlm_sql_db2"
        server = "EDRRADIUS"
        port = 0
        login = "edribmus"
        password = <<< secret >>>
        radius_db = "edr"
        read_groups = yes
        read_profiles = yes
        read_clients = no
        delete_stale_sessions = yes
        sql_user_name = "%{User-Name}"
        logfile = ""
        default_user_profile = ""
        client_query = "SELECT id, nasname, shortname, type, secret, 
server FROM nas"
        authorize_check_query = "SELECT id, username, attribute, value, op 
FROM edr.runstatus 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-Group}' ORDER BY id"
        authorize_group_reply_query = "SELECT id, groupname, attribute, 
value, op FROM radgroupreply WHERE groupname = '%{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}.query}"
    type {
     accounting-on {
        query = "UPDATE radacct SET acctstoptime = 
FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime      = 
'%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), 
acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE 
acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND 
acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})"
     }
     accounting-off {
        query = "UPDATE radacct SET acctstoptime = 
FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime      = 
'%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), 
acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE 
acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND 
acctstarttime <= FROM_UNIXTIME(%{integer:Event-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) VALUES ('%{Acct-Session-Id}', 
'%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', 
'%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', 
FROM_UNIXTIME(%{integer:Event-Timestamp}), 
FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', 
'%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', 
'%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', 
'%{Framed-IP-Address}')"
     }
     interim-update {
        query = "UPDATE radacct SET acctupdatetime  = 
(@acctupdatetime_old:=acctupdatetime), acctupdatetime  = 
FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval    = 
%{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), 
framedipaddress = '%{Framed-IP-Address}', acctsessiontime = 
%{%{Acct-Session-Time}:-NULL}, acctinputoctets = 
'%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', 
acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | 
'%{%{Acct-Output-Octets}:-0}' WHERE AcctUniqueId = 
'%{Acct-Unique-Session-Id}'"
     }
     stop {
        query = "UPDATE radacct SET acctstoptime        = 
FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime      = 
%{%{Acct-Session-Time}:-NULL}, acctinputoctets  = 
'%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', 
acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | 
'%{%{Acct-Output-Octets}:-0}', acctterminatecause = 
'%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE 
AcctUniqueId = '%{Acct-Unique-Session-Id}'"
     }
    }
   }
   post-auth {
        reference = ".query"
        query = "INSERT INTO radpostauth (username, pass, reply, authdate) 
VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', 
'%{reply:Packet-Type}', '%S')"
   }
  }
rlm_sql (sql): Driver rlm_sql_db2 (module rlm_sql_db2) loaded and linked
Creating attribute SQL-Group
  # Loading module "auth_log" from file 
/etc/edr_raddb/mods-enabled/detail.log
  detail auth_log {
        filename = 
"/var/log/radiusd/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/edr_raddb/mods-enabled/detail.log
  detail reply_log {
        filename = 
"/var/log/radiusd/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/edr_raddb/mods-enabled/detail.log
  detail pre_proxy_log {
        filename = 
"/var/log/radiusd/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/edr_raddb/mods-enabled/detail.log
  detail post_proxy_log {
        filename = 
"/var/log/radiusd/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_linelog
  # Loading module "linelog" from file /etc/edr_raddb/mods-enabled/linelog
  linelog {
        filename = "/var/log/radiusd/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/edr_raddb/mods-enabled/linelog
  linelog log_accounting {
        filename = "/var/log/radiusd/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/edr_raddb/mods-enabled/logintime
  logintime {
        minimum_timeout = 60
  }
  # Loaded module rlm_expiration
  # Loading module "expiration" from file 
/etc/edr_raddb/mods-enabled/expiration
  # Loaded module rlm_unix
  # Loading module "unix" from file /etc/edr_raddb/mods-enabled/unix
  unix {
        radwtmp = "/var/log/radiusd/radwtmp"
  }
Creating attribute Unix-Group
  # Loaded module rlm_date
  # Loading module "date" from file /etc/edr_raddb/mods-enabled/date
  date {
        format = "%b %e %Y %H:%M:%S %Z"
        utc = no
  }
  # Loading module "wispr2date" from file /etc/edr_raddb/mods-enabled/date
  date wispr2date {
        format = "%Y-%m-%dT%H:%M:%S"
        utc = no
  }
  # Loaded module rlm_chap
  # Loading module "chap" from file /etc/edr_raddb/mods-enabled/chap
  # Loading module "exec" from file /etc/edr_raddb/mods-enabled/exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
        timeout = 5
  }
  # Loaded module rlm_utf8
  # Loading module "utf8" from file /etc/edr_raddb/mods-enabled/utf8
  # Loading module "ntlm_auth" from file 
/etc/edr_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
        timeout = 5
  }
  # Loaded module rlm_passwd
  # Loading module "etc_passwd" from file 
/etc/edr_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_cache
  # Loading module "cache_eap" from file 
/etc/edr_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_realm
  # Loading module "IPASS" from file /etc/edr_raddb/mods-enabled/realm
  realm IPASS {
        format = "prefix"
        delimiter = "/"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "suffix" from file /etc/edr_raddb/mods-enabled/realm
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "bangpath" from file /etc/edr_raddb/mods-enabled/realm
  realm bangpath {
        format = "prefix"
        delimiter = "!"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "realmpercent" from file 
/etc/edr_raddb/mods-enabled/realm
  realm realmpercent {
        format = "suffix"
        delimiter = "%"
        ignore_default = no
        ignore_null = no
  }
  # Loading module "ntdomain" from file /etc/edr_raddb/mods-enabled/realm
  realm ntdomain {
        format = "prefix"
        delimiter = "\\"
        ignore_default = no
        ignore_null = no
  }
  # Loaded module rlm_dynamic_clients
  # Loading module "dynamic_clients" from file 
/etc/edr_raddb/mods-enabled/dynamic_clients
  # Loaded module rlm_pap
  # Loading module "pap" from file /etc/edr_raddb/mods-enabled/pap
  pap {
        normalise = yes
  }
  # Loaded module rlm_always
  # Loading module "reject" from file /etc/edr_raddb/mods-enabled/always
  always reject {
        rcode = "reject"
        simulcount = 0
        mpp = no
  }
  # Loading module "fail" from file /etc/edr_raddb/mods-enabled/always
  always fail {
        rcode = "fail"
        simulcount = 0
        mpp = no
  }
  # Loading module "ok" from file /etc/edr_raddb/mods-enabled/always
  always ok {
        rcode = "ok"
        simulcount = 0
        mpp = no
  }
  # Loading module "handled" from file /etc/edr_raddb/mods-enabled/always
  always handled {
        rcode = "handled"
        simulcount = 0
        mpp = no
  }
  # Loading module "invalid" from file /etc/edr_raddb/mods-enabled/always
  always invalid {
        rcode = "invalid"
        simulcount = 0
        mpp = no
  }
  # Loading module "userlock" from file /etc/edr_raddb/mods-enabled/always
  always userlock {
        rcode = "userlock"
        simulcount = 0
        mpp = no
  }
  # Loading module "notfound" from file /etc/edr_raddb/mods-enabled/always
  always notfound {
        rcode = "notfound"
        simulcount = 0
        mpp = no
  }
  # Loading module "noop" from file /etc/edr_raddb/mods-enabled/always
  always noop {
        rcode = "noop"
        simulcount = 0
        mpp = no
  }
  # Loading module "updated" from file /etc/edr_raddb/mods-enabled/always
  always updated {
        rcode = "updated"
        simulcount = 0
        mpp = no
  }
  instantiate {
  }
  # Instantiating module "files" from file 
/etc/edr_raddb/mods-enabled/files
reading pairlist file /etc/edr_raddb/mods-config/files/authorize
reading pairlist file /etc/edr_raddb/mods-config/files/accounting
reading pairlist file /etc/edr_raddb/mods-config/files/pre-proxy
  # Instantiating module "preprocess" from file 
/etc/edr_raddb/mods-enabled/preprocess
reading pairlist file /etc/edr_raddb/mods-config/preprocess/huntgroups
reading pairlist file /etc/edr_raddb/mods-config/preprocess/hints
  # Instantiating module "detail" from file 
/etc/edr_raddb/mods-enabled/detail
  # Instantiating module "mschap" from file 
/etc/edr_raddb/mods-enabled/mschap
rlm_mschap (mschap): using internal authentication
  # Instantiating module "attr_filter.post-proxy" from file 
/etc/edr_raddb/mods-enabled/attr_filter
reading pairlist file /etc/edr_raddb/mods-config/attr_filter/post-proxy
  # Instantiating module "attr_filter.pre-proxy" from file 
/etc/edr_raddb/mods-enabled/attr_filter
reading pairlist file /etc/edr_raddb/mods-config/attr_filter/pre-proxy
  # Instantiating module "attr_filter.access_reject" from file 
/etc/edr_raddb/mods-enabled/attr_filter
reading pairlist file /etc/edr_raddb/mods-config/attr_filter/access_reject
  # Instantiating module "attr_filter.access_challenge" from file 
/etc/edr_raddb/mods-enabled/attr_filter
reading pairlist file 
/etc/edr_raddb/mods-config/attr_filter/access_challenge
  # Instantiating module "attr_filter.accounting_response" from file 
/etc/edr_raddb/mods-enabled/attr_filter
reading pairlist file 
/etc/edr_raddb/mods-config/attr_filter/accounting_response
  # Instantiating module "sql" from file /etc/edr_raddb/mods-enabled/sql
rlm_sql (sql): Attempting to connect to database "edr"
rlm_sql (sql): Initialising connection pool
   pool {
        start = 5
        min = 3
        max = 128
        spare = 10
        uses = 0
        lifetime = 0
        cleanup_interval = 30
        idle_timeout = 60
        retry_delay = 30
        spread = no
   }
rlm_sql (sql): Opening additional connection (0), 1 of 128 pending slots 
used
rlm_sql (sql): Opening additional connection (1), 1 of 127 pending slots 
used
rlm_sql (sql): Opening additional connection (2), 1 of 126 pending slots 
used
rlm_sql (sql): Opening additional connection (3), 1 of 125 pending slots 
used
rlm_sql (sql): Opening additional connection (4), 1 of 124 pending slots 
used
  # Instantiating module "auth_log" from file 
/etc/edr_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/edr_raddb/mods-enabled/detail.log
  # Instantiating module "pre_proxy_log" from file 
/etc/edr_raddb/mods-enabled/detail.log
  # Instantiating module "post_proxy_log" from file 
/etc/edr_raddb/mods-enabled/detail.log
  # Instantiating module "linelog" from file 
/etc/edr_raddb/mods-enabled/linelog
  # Instantiating module "log_accounting" from file 
/etc/edr_raddb/mods-enabled/linelog
  # Instantiating module "logintime" from file 
/etc/edr_raddb/mods-enabled/logintime
  # Instantiating module "expiration" from file 
/etc/edr_raddb/mods-enabled/expiration
  # Instantiating module "etc_passwd" from file 
/etc/edr_raddb/mods-enabled/passwd
rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no
  # Instantiating module "cache_eap" from file 
/etc/edr_raddb/mods-enabled/cache_eap
rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) 
loaded and linked
  # Instantiating module "IPASS" from file 
/etc/edr_raddb/mods-enabled/realm
  # Instantiating module "suffix" from file 
/etc/edr_raddb/mods-enabled/realm
  # Instantiating module "bangpath" from file 
/etc/edr_raddb/mods-enabled/realm
  # Instantiating module "realmpercent" from file 
/etc/edr_raddb/mods-enabled/realm
  # Instantiating module "ntdomain" from file 
/etc/edr_raddb/mods-enabled/realm
  # Instantiating module "pap" from file /etc/edr_raddb/mods-enabled/pap
  # Instantiating module "reject" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "fail" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "ok" from file /etc/edr_raddb/mods-enabled/always
  # Instantiating module "handled" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "invalid" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "userlock" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "notfound" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "noop" from file 
/etc/edr_raddb/mods-enabled/always
  # Instantiating module "updated" from file 
/etc/edr_raddb/mods-enabled/always
 } # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /etc/edr_raddb/radiusd.conf
} # server
server default { # from file /etc/edr_raddb/sites-enabled/default
 # Loading authorize {...}
 # Loading post-auth {...}
} # server default
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
   }
}
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 proxy address * port 37769
Listening on proxy address :: port 17802
Ready to process requests
(0) Received Access-Request Id 191 from 9.44.14.216:1953 to 
9.44.14.148:1812 length 65
(0)   User-Name = "SI_radius_keepalive"
(0)   User-Password = "oԨW?\014\222\315>I2ꎯ\026\251"
(0)   Service-Type = Outbound-User
(0) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(0)   authorize {
(0)     [files] = noop
(0)     update control {
(0)       &Auth-Type := Accept
(0)     } # update control = noop
(0)   } # authorize = noop
(0) Found Auth-Type = Accept
(0) Auth-Type = Accept, accepting the user
(0) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(0)   post-auth {
(0)     policy check_sql_status {
(0)       update control {
(0)         EXPAND %{User-Name}
(0)            --> SI_radius_keepalive
(0)         SQL-User-Name set to 'SI_radius_keepalive'
rlm_sql (sql): Reserved connection (0)
(0)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (0)
Need 5 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (5), 1 of 123 pending slots 
used
(0)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(0)            --> 1
(0)         &Tmp-Integer-0 := 1
(0)       } # update control = noop
(0)       if (control:Tmp-Integer-0 < 1) {
(0)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(0)     } # policy check_sql_status = noop
(0)     check_for_cisco_AP { ... } # empty sub-section is ignored
(0)     policy check_for_bypassed_MAC {
(0)       if (User-Name == "SI_radius_keepalive") {
(0)       if (User-Name == "SI_radius_keepalive")  -> TRUE
(0)       if (User-Name == "SI_radius_keepalive")  {
(0)         update reply {
(0)           &Reply-Message += "EDR User SI_radius_keepalive bypassed, 
EDR Accept"
(0)         } # update reply = noop
(0)         update control {
(0)           &Auth-Type := Accept
(0)         } # update control = noop
(0)         [handled] = handled
(0)       } # if (User-Name == "SI_radius_keepalive")  = handled
(0)     } # policy check_for_bypassed_MAC = handled
(0)   } # post-auth = handled
(0) EXPAND %{&reply:Reply-Message}
(0)    --> EDR User SI_radius_keepalive bypassed, EDR Accept
(0) Login OK: [SI_radius_keepalive/oԨW????>I2ꎯ??] (from client 
IBM-9client port 0) EDR User SI_radius_keepalive bypassed, EDR Accept
(0) Sent Access-Accept Id 191 from 9.44.14.148:1812 to 9.44.14.216:1953 
length 0
(0)   Reply-Message += "EDR User SI_radius_keepalive bypassed, EDR Accept"
(0) Finished request
Waking up in 1.9 seconds.
(1) Received Access-Request Id 143 from 9.44.14.217:2000 to 
9.44.14.148:1812 length 65
(1)   User-Name = "SI_radius_keepalive"
(1)   User-Password = "k\037(#\356X\374e\024\334\371\240\365\212\024\262"
(1)   Service-Type = Outbound-User
(1) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(1)   authorize {
(1)     [files] = noop
(1)     update control {
(1)       &Auth-Type := Accept
(1)     } # update control = noop
(1)   } # authorize = noop
(1) Found Auth-Type = Accept
(1) Auth-Type = Accept, accepting the user
(1) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(1)   post-auth {
(1)     policy check_sql_status {
(1)       update control {
(1)         EXPAND %{User-Name}
(1)            --> SI_radius_keepalive
(1)         SQL-User-Name set to 'SI_radius_keepalive'
rlm_sql (sql): Reserved connection (1)
(1)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (1)
(1)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(1)            --> 1
(1)         &Tmp-Integer-0 := 1
(1)       } # update control = noop
(1)       if (control:Tmp-Integer-0 < 1) {
(1)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(1)     } # policy check_sql_status = noop
(1)     check_for_cisco_AP { ... } # empty sub-section is ignored
(1)     policy check_for_bypassed_MAC {
(1)       if (User-Name == "SI_radius_keepalive") {
(1)       if (User-Name == "SI_radius_keepalive")  -> TRUE
(1)       if (User-Name == "SI_radius_keepalive")  {
(1)         update reply {
(1)           &Reply-Message += "EDR User SI_radius_keepalive bypassed, 
EDR Accept"
(1)         } # update reply = noop
(1)         update control {
(1)           &Auth-Type := Accept
(1)         } # update control = noop
(1)         [handled] = handled
(1)       } # if (User-Name == "SI_radius_keepalive")  = handled
(1)     } # policy check_for_bypassed_MAC = handled
(1)   } # post-auth = handled
(1) EXPAND %{&reply:Reply-Message}
(1)    --> EDR User SI_radius_keepalive bypassed, EDR Accept
(1) Login OK: [SI_radius_keepalive/k?(#?X?e????????] (from client 
IBM-9client port 0) EDR User SI_radius_keepalive bypassed, EDR Accept
(1) Sent Access-Accept Id 143 from 9.44.14.148:1812 to 9.44.14.217:2000 
length 0
(1)   Reply-Message += "EDR User SI_radius_keepalive bypassed, EDR Accept"
(1) Finished request
Waking up in 1.9 seconds.
(0) Cleaning up request packet ID 191 with timestamp +4
(1) Cleaning up request packet ID 143 with timestamp +4
Ready to process requests
(2) Received Access-Request Id 192 from 9.44.14.216:1101 to 
9.44.14.148:1812 length 65
(2)   User-Name = "SI_radius_keepalive"
(2)   User-Password = 
"\343\022\035\323\355JA\032\232\367\242\026\266\035=\033"
(2)   Service-Type = Outbound-User
(2) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(2)   authorize {
(2)     [files] = noop
(2)     update control {
(2)       &Auth-Type := Accept
(2)     } # update control = noop
(2)   } # authorize = noop
(2) Found Auth-Type = Accept
(2) Auth-Type = Accept, accepting the user
(2) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(2)   post-auth {
(2)     policy check_sql_status {
(2)       update control {
(2)         EXPAND %{User-Name}
(2)            --> SI_radius_keepalive
(2)         SQL-User-Name set to 'SI_radius_keepalive'
rlm_sql (sql): Reserved connection (2)
(2)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (2)
Need 4 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (6), 1 of 122 pending slots 
used
(2)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(2)            --> 1
(2)         &Tmp-Integer-0 := 1
(2)       } # update control = noop
(2)       if (control:Tmp-Integer-0 < 1) {
(2)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(2)     } # policy check_sql_status = noop
(2)     check_for_cisco_AP { ... } # empty sub-section is ignored
(2)     policy check_for_bypassed_MAC {
(2)       if (User-Name == "SI_radius_keepalive") {
(2)       if (User-Name == "SI_radius_keepalive")  -> TRUE
(2)       if (User-Name == "SI_radius_keepalive")  {
(2)         update reply {
(2)           &Reply-Message += "EDR User SI_radius_keepalive bypassed, 
EDR Accept"
(2)         } # update reply = noop
(2)         update control {
(2)           &Auth-Type := Accept
(2)         } # update control = noop
(2)         [handled] = handled
(2)       } # if (User-Name == "SI_radius_keepalive")  = handled
(2)     } # policy check_for_bypassed_MAC = handled
(2)   } # post-auth = handled
(2) EXPAND %{&reply:Reply-Message}
(2)    --> EDR User SI_radius_keepalive bypassed, EDR Accept
(2) Login OK: [SI_radius_keepalive/?????JA???????=?] (from client 
IBM-9client port 0) EDR User SI_radius_keepalive bypassed, EDR Accept
(2) Sent Access-Accept Id 192 from 9.44.14.148:1812 to 9.44.14.216:1101 
length 0
(2)   Reply-Message += "EDR User SI_radius_keepalive bypassed, EDR Accept"
(2) Finished request
Waking up in 1.9 seconds.
(2) Cleaning up request packet ID 192 with timestamp +9
Ready to process requests
(3) Received Access-Request Id 144 from 9.44.14.217:1245 to 
9.44.14.148:1812 length 65
(3)   User-Name = "SI_radius_keepalive"
(3)   User-Password = "\345O|H\347\312`a\315\036.\210h\201]\232"
(3)   Service-Type = Outbound-User
(3) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(3)   authorize {
(3)     [files] = noop
(3)     update control {
(3)       &Auth-Type := Accept
(3)     } # update control = noop
(3)   } # authorize = noop
(3) Found Auth-Type = Accept
(3) Auth-Type = Accept, accepting the user
(3) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(3)   post-auth {
(3)     policy check_sql_status {
(3)       update control {
(3)         EXPAND %{User-Name}
(3)            --> SI_radius_keepalive
(3)         SQL-User-Name set to 'SI_radius_keepalive'
rlm_sql (sql): Reserved connection (3)
(3)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (3)
Need 3 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (7), 1 of 121 pending slots 
used
(3)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(3)            --> 1
(3)         &Tmp-Integer-0 := 1
(3)       } # update control = noop
(3)       if (control:Tmp-Integer-0 < 1) {
(3)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(3)     } # policy check_sql_status = noop
(3)     check_for_cisco_AP { ... } # empty sub-section is ignored
(3)     policy check_for_bypassed_MAC {
(3)       if (User-Name == "SI_radius_keepalive") {
(3)       if (User-Name == "SI_radius_keepalive")  -> TRUE
(3)       if (User-Name == "SI_radius_keepalive")  {
(3)         update reply {
(3)           &Reply-Message += "EDR User SI_radius_keepalive bypassed, 
EDR Accept"
(3)         } # update reply = noop
(3)         update control {
(3)           &Auth-Type := Accept
(3)         } # update control = noop
(3)         [handled] = handled
(3)       } # if (User-Name == "SI_radius_keepalive")  = handled
(3)     } # policy check_for_bypassed_MAC = handled
(3)   } # post-auth = handled
(3) EXPAND %{&reply:Reply-Message}
(3)    --> EDR User SI_radius_keepalive bypassed, EDR Accept
(3) Login OK: [SI_radius_keepalive/?O|H??`a??.?h?]?] (from client 
IBM-9client port 0) EDR User SI_radius_keepalive bypassed, EDR Accept
(3) Sent Access-Accept Id 144 from 9.44.14.148:1812 to 9.44.14.217:1245 
length 0
(3)   Reply-Message += "EDR User SI_radius_keepalive bypassed, EDR Accept"
(3) Finished request
Waking up in 1.9 seconds.
(3) Cleaning up request packet ID 144 with timestamp +14
Ready to process requests
....
(5502) Cleaning up request packet ID 144 with timestamp +338
(5538) Received Access-Request Id 189 from 127.0.0.1:24740 to 
127.0.0.1:1812 length 64
(5538)   User-Name = "00000000000R"
(5538)   NAS-IP-Address = 9.44.14.137
(5538)   NAS-Port = 10
(5538)   Message-Authenticator = 0xda40c1552d213d34cc95f4298773670d
(5538) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(5538)   authorize {
(5538)     [files] = noop
(5538)     update control {
(5538)       &Auth-Type := Accept
(5538)     } # update control = noop
(5538)   } # authorize = noop
(5538) Found Auth-Type = Accept
(5538) Auth-Type = Accept, accepting the user
(5538) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(5538)   post-auth {
(5538)     policy check_sql_status {
(5538)       update control {
(5538)         EXPAND %{User-Name}
(5538)            --> 00000000000R
(5538)         SQL-User-Name set to '00000000000R'
rlm_sql (sql): Reserved connection (7)
(5538)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (7)
(5538)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(5538)            --> 1
(5538)         &Tmp-Integer-0 := 1
(5538)       } # update control = noop
(5538)       if (control:Tmp-Integer-0 < 1) {
(5538)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(5538)     } # policy check_sql_status = noop
(5538)     check_for_cisco_AP { ... } # empty sub-section is ignored
(5538)     policy check_for_bypassed_MAC {
(5538)       if (User-Name == "SI_radius_keepalive") {
(5538)       if (User-Name == "SI_radius_keepalive")  -> FALSE
(5538)       if (User-Name == "nessus") {
(5538)       if (User-Name == "nessus")  -> FALSE
(5538)       elsif (User-Name == "00000000000R") {
(5538)       elsif (User-Name == "00000000000R")  -> TRUE
(5538)       elsif (User-Name == "00000000000R")  {
(5538)         update reply {
(5538)           &Reply-Message += "EDR 00000000000R bypassed for AOHCS 
Health Check, EDR Reject"
(5538)         } # update reply = noop
(5538)         update control {
(5538)           &Auth-Type := Reject
(5538)         } # update control = noop
(5538)         [reject] = reject
(5538)       } # elsif (User-Name == "00000000000R")  = reject
(5538)     } # policy check_for_bypassed_MAC = reject
(5538)   } # post-auth = reject
(5538) Using Post-Auth-Type Reject
(5538) Post-Auth-Type sub-section not found.  Ignoring.
(5538) # Executing group from file /etc/edr_raddb/sites-enabled/default
(5538) EXPAND %{&reply:Reply-Message}
(5538)    --> EDR 00000000000R bypassed for AOHCS Health Check, EDR Reject
(5538) Rejected in post-auth: [00000000000R/<via Auth-Type = Reject>] 
(from client localhost port 10) EDR 00000000000R bypassed for AOHCS Health 
Check, EDR Reject
(5538) EXPAND %{&reply:Reply-Message}
(5538)    --> EDR 00000000000R bypassed for AOHCS Health Check, EDR Reject
(5538) Login incorrect: [00000000000R/<via Auth-Type = Reject>] (from 
client localhost port 10) EDR 00000000000R bypassed for AOHCS Health 
Check, EDR Reject
(5538) Sent Access-Reject Id 189 from 127.0.0.1:1812 to 127.0.0.1:24740 
length 0
(5538)   Reply-Message += "EDR 00000000000R bypassed for AOHCS Health 
Check, EDR Reject"
(5538) Finished request
(5503) Cleaning up request packet ID 142 with timestamp +338
(5539) Received Access-Request Id 118 from 127.0.0.1:40924 to 
127.0.0.1:1812 length 64
(5539)   User-Name = "000000099999"
(5539)   NAS-IP-Address = 9.44.14.137
(5539)   NAS-Port = 10
(5539)   Message-Authenticator = 0x1bdead5678e95af1770b0b22d7ce5284
(5539) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(5539)   authorize {
(5539)     [files] = noop
(5539)     update control {
(5539)       &Auth-Type := Accept
(5539)     } # update control = noop
(5539)   } # authorize = noop
(5539) Found Auth-Type = Accept
(5539) Auth-Type = Accept, accepting the user
(5539) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(5539)   post-auth {
(5539)     policy check_sql_status {
(5539)       update control {
(5539)         EXPAND %{User-Name}
(5539)            --> 000000099999
(5539)         SQL-User-Name set to '000000099999'
rlm_sql (sql): Reserved connection (4)
(5539)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
Could not execute statement "SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR"
(5539)         ERROR: rlm_sql_db2: HY014: [IBM][CLI Driver] CLI0129E  An 
attempt to allocate a handle failed because there are no more handles to 
allocate. SQLSTATE=HY014
(5539)         ERROR: SQL query failed: server error
rlm_sql (sql): Released connection (4)
(5539)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(5539)            -->
(5539)         &Tmp-Integer-0 := 0
(5539)       } # update control = noop
(5539)       if (control:Tmp-Integer-0 < 1) {
(5539)       if (control:Tmp-Integer-0 < 1)  -> TRUE
(5539)       if (control:Tmp-Integer-0 < 1)  {
(5539)         policy fail_open {
(5539)           update reply {
(5539)             EXPAND EDR req_num:%n req_id:%I fail_open
(5539)                --> EDR req_num:5539 req_id:118 fail_open
(5539)             &Reply-Message += EDR req_num:5539 req_id:118 fail_open
(5539)           } # update reply = noop
(5539)           update control {
(5539)             &Auth-Type := Accept
(5539)           } # update control = noop
(5539)           [handled] = handled
(5539)         } # policy fail_open = handled
(5539)       } # if (control:Tmp-Integer-0 < 1)  = handled
(5539)     } # policy check_sql_status = handled
(5539)   } # post-auth = handled
(5539) EXPAND %{&reply:Reply-Message}
(5539)    --> EDR req_num:5539 req_id:118 fail_open
(5539) Login OK: [000000099999/<via Auth-Type = Accept>] (from client 
localhost port 10) EDR req_num:5539 req_id:118 fail_open
(5539) Sent Access-Accept Id 118 from 127.0.0.1:1812 to 127.0.0.1:40924 
length 0
(5539)   Reply-Message += "EDR req_num:5539 req_id:118 fail_open"
(5539) Finished request
(5504) Cleaning up request packet ID 135 with timestamp +338
(5540) Received Access-Request Id 161 from 127.0.0.1:29338 to 
127.0.0.1:1812 length 64
(5540)   User-Name = "000000000000"
(5540)   NAS-IP-Address = 9.44.14.137
(5540)   NAS-Port = 10
(5540)   Message-Authenticator = 0x7afd0d4c0f5f7f5939d4b862a7fe7c29
(5540) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(5540)   authorize {
(5540)     [files] = noop
(5540)     update control {
(5540)       &Auth-Type := Accept
(5540)     } # update control = noop
(5540)   } # authorize = noop
(5540) Found Auth-Type = Accept
(5540) Auth-Type = Accept, accepting the user
(5540) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(5540)   post-auth {
(5540)     policy check_sql_status {
(5540)       update control {
(5540)         EXPAND %{User-Name}
(5540)            --> 000000000000
(5540)         SQL-User-Name set to '000000000000'
rlm_sql (sql): Reserved connection (8)
(5540)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (8)
(5540)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(5540)            --> 1
(5540)         &Tmp-Integer-0 := 1
(5540)       } # update control = noop
(5540)       if (control:Tmp-Integer-0 < 1) {
(5540)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(5540)     } # policy check_sql_status = noop
(5540)     check_for_cisco_AP { ... } # empty sub-section is ignored
(5540)     policy check_for_bypassed_MAC {
(5540)       if (User-Name == "SI_radius_keepalive") {
(5540)       if (User-Name == "SI_radius_keepalive")  -> FALSE
(5540)       if (User-Name == "nessus") {
(5540)       if (User-Name == "nessus")  -> FALSE
(5540)       elsif (User-Name == "00000000000R") {
(5540)       elsif (User-Name == "00000000000R")  -> FALSE
(5540)     } # policy check_for_bypassed_MAC = noop
(5540)     policy check_for_ignore {
(5540)       update control {
rlm_sql (sql): Reserved connection (0)
rlm_sql (sql): Released connection (0)
(5540)         EXPAND %{User-Name}
(5540)            --> 000000000000
(5540)         SQL-User-Name set to '000000000000'
rlm_sql (sql): Reserved connection (9)
(5540)         Executing select query: SELECT COUNT(*) FROM edr.failed 
WHERE username='000000000000' AND authdate >= (CURRENT TIMESTAMP - 1 DAYS) 
WITH UR
rlm_sql (sql): Released connection (9)
(5540)         EXPAND %{sql:SELECT COUNT(*) FROM edr.failed WHERE 
username='%{User-Name}' AND authdate >= (CURRENT TIMESTAMP - 1 DAYS) WITH 
UR }
(5540)            --> 36
(5540)         &Tmp-Integer-0 := 36
(5540)       } # update control = noop
(5540)       if (control:Tmp-Integer-0 > 58) {
(5540)       if (control:Tmp-Integer-0 > 58)  -> FALSE
(5540)     } # policy check_for_ignore = noop
(5540)     policy check_for_registered_MAC {
(5540)       update control {
rlm_sql (sql): Reserved connection (5)
rlm_sql (sql): Released connection (5)
(5540)         EXPAND %{User-Name}
(5540)            --> 000000000000
(5540)         SQL-User-Name set to '000000000000'
rlm_sql (sql): Reserved connection (1)
(5540)         Executing select query: SELECT COUNT(*) FROM ldap.ldapsync 
WHERE mac='000000000000' WITH UR
rlm_sql (sql): Released connection (1)
(5540)         EXPAND %{sql:SELECT COUNT(*) FROM ldap.ldapsync WHERE 
mac='%{User-Name}' WITH UR}
(5540)            --> 1
(5540)         &Tmp-Integer-0 := 1
(5540)       } # update control = noop
(5540)       if (control:Tmp-Integer-0 > 0) {
(5540)       if (control:Tmp-Integer-0 > 0)  -> TRUE
(5540)       if (control:Tmp-Integer-0 > 0)  {
(5540)         update reply {
(5540)           EXPAND EDR req_num:%n req_id:%I MAC %{User-Name} from 
relay %{Packet-Src-IP-Address} is registered, EDR accept
(5540)              --> EDR req_num:5540 req_id:161 MAC 000000000000 from 
relay 127.0.0.1 is registered, EDR accept
(5540)           &Reply-Message := EDR req_num:5540 req_id:161 MAC 
000000000000 from relay 127.0.0.1 is registered, EDR accept
(5540)         } # update reply = noop
(5540)         update control {
(5540)           &Auth-Type := Accept
(5540)         } # update control = noop
(5540)         [handled] = handled
(5540)       } # if (control:Tmp-Integer-0 > 0)  = handled
(5540)     } # policy check_for_registered_MAC = handled
(5540)   } # post-auth = handled
(5540) EXPAND %{&reply:Reply-Message}
(5540)    --> EDR req_num:5540 req_id:161 MAC 000000000000 from relay 
127.0.0.1 is registered, EDR accept
(5540) Login OK: [000000000000/<via Auth-Type = Accept>] (from client 
localhost port 10) EDR req_num:5540 req_id:161 MAC 000000000000 from relay 
127.0.0.1 is registered, EDR accept
(5540) Sent Access-Accept Id 161 from 127.0.0.1:1812 to 127.0.0.1:29338 
length 0
(5540)   Reply-Message := "EDR req_num:5540 req_id:161 MAC 000000000000 
from relay 127.0.0.1 is registered, EDR accept"
(5540) Finished request
(5505) Cleaning up request packet ID 136 with timestamp +338
(5541) Received Access-Request Id 151 from 127.0.0.1:30962 to 
127.0.0.1:1812 length 64
(5541)   User-Name = "000000000001"
(5541)   NAS-IP-Address = 9.44.14.137
(5541)   NAS-Port = 10
(5541)   Message-Authenticator = 0x24c78b0147d18e8b4c975734b2daaf1d
(5541) # Executing section authorize from file 
/etc/edr_raddb/sites-enabled/default
(5541)   authorize {
(5541)     [files] = noop
(5541)     update control {
(5541)       &Auth-Type := Accept
(5541)     } # update control = noop
(5541)   } # authorize = noop
(5541) Found Auth-Type = Accept
(5541) Auth-Type = Accept, accepting the user
(5541) # Executing section post-auth from file 
/etc/edr_raddb/sites-enabled/default
(5541)   post-auth {
(5541)     policy check_sql_status {
(5541)       update control {
(5541)         EXPAND %{User-Name}
(5541)            --> 000000000001
(5541)         SQL-User-Name set to '000000000001'
rlm_sql (sql): Reserved connection (2)
(5541)         Executing select query: SELECT COUNT(*) FROM edr.runstatus 
WHERE status='NORMALOP' WITH UR
rlm_sql (sql): Released connection (2)
(5541)         EXPAND %{sql:SELECT COUNT(*) FROM edr.runstatus WHERE 
status='NORMALOP' WITH UR}
(5541)            --> 1
(5541)         &Tmp-Integer-0 := 1
(5541)       } # update control = noop
(5541)       if (control:Tmp-Integer-0 < 1) {
(5541)       if (control:Tmp-Integer-0 < 1)  -> FALSE
(5541)     } # policy check_sql_status = noop
(5541)     check_for_cisco_AP { ... } # empty sub-section is ignored
(5541)     policy check_for_bypassed_MAC {
(5541)       if (User-Name == "SI_radius_keepalive") {
(5541)       if (User-Name == "SI_radius_keepalive")  -> FALSE
(5541)       if (User-Name == "nessus") {
(5541)       if (User-Name == "nessus")  -> FALSE
(5541)       elsif (User-Name == "00000000000R") {
(5541)       elsif (User-Name == "00000000000R")  -> FALSE
(5541)     } # policy check_for_bypassed_MAC = noop
(5541)     policy check_for_ignore {
(5541)       update control {
rlm_sql (sql): Reserved connection (6)
rlm_sql (sql): Released connection (6)
(5541)         EXPAND %{User-Name}
(5541)            --> 000000000001
(5541)         SQL-User-Name set to '000000000001'
rlm_sql (sql): Reserved connection (3)
(5541)         Executing select query: SELECT COUNT(*) FROM edr.failed 
WHERE username='000000000001' AND authdate >= (CURRENT TIMESTAMP - 1 DAYS) 
WITH UR
rlm_sql (sql): Released connection (3)
(5541)         EXPAND %{sql:SELECT COUNT(*) FROM edr.failed WHERE 
username='%{User-Name}' AND authdate >= (CURRENT TIMESTAMP - 1 DAYS) WITH 
UR }
(5541)            --> 44
(5541)         &Tmp-Integer-0 := 44
(5541)       } # update control = noop
(5541)       if (control:Tmp-Integer-0 > 58) {
(5541)       if (control:Tmp-Integer-0 > 58)  -> FALSE
(5541)     } # policy check_for_ignore = noop
(5541)     policy check_for_registered_MAC {
(5541)       update control {
rlm_sql (sql): Reserved connection (7)
rlm_sql (sql): Released connection (7)
(5541)         EXPAND %{User-Name}
(5541)            --> 000000000001
(5541)         SQL-User-Name set to '000000000001'
rlm_sql (sql): Reserved connection (4)
(5541)         Executing select query: SELECT COUNT(*) FROM ldap.ldapsync 
WHERE mac='000000000001' WITH UR
Could not execute statement "SELECT COUNT(*) FROM ldap.ldapsync WHERE 
mac='000000000001' WITH UR"
(5541)         ERROR: rlm_sql_db2: HY014: [IBM][CLI Driver] CLI0129E  An 
attempt to allocate a handle failed because there are no more handles to 
allocate. SQLSTATE=HY014
(5541)         ERROR: SQL query failed: server error
rlm_sql (sql): Released connection (4)
(5541)         EXPAND %{sql:SELECT COUNT(*) FROM ldap.ldapsync WHERE 
mac='%{User-Name}' WITH UR}
(5541)            -->
(5541)         &Tmp-Integer-0 := 0
(5541)       } # update control = noop
(5541)       if (control:Tmp-Integer-0 > 0) {
(5541)       if (control:Tmp-Integer-0 > 0)  -> FALSE
(5541)     } # policy check_for_registered_MAC = noop
(5541)     policy edr_count_and_reject {
(5541)       if (Client-Shortname != "L2R") {
(5541)       EXPAND Client-Shortname
(5541)          --> localhost
(5541)       if (Client-Shortname != "L2R")  -> TRUE
(5541)       if (Client-Shortname != "L2R")  {
(5541)         update control {
rlm_sql (sql): Reserved connection (8)
rlm_sql (sql): Released connection (8)
rlm_sql (sql): Reserved connection (0)
rlm_sql (sql): Released connection (0)
(5541)           EXPAND %{User-Name}
(5541)              --> 000000000001
(5541)           SQL-User-Name set to '000000000001'
rlm_sql (sql): Reserved connection (9)
(5541)           Executing query: INSERT INTO edr.failed 
(username,authdate,addr) VALUES ('000000000001', CURRENT TIMESTAMP, 
'127.0.0.1')
rlm_sql (sql): Released connection (9)
(5541)           EXPAND %{sql:INSERT INTO edr.failed 
(username,authdate,addr) VALUES ('%{User-Name}', CURRENT TIMESTAMP, 
'%{Packet-Src-IP-Address}')}
(5541)              --> 1
(5541)           &Tmp-Integer-0 := 1
rlm_sql (sql): Reserved connection (5)
rlm_sql (sql): Released connection (5)
(5541)           EXPAND %{User-Name}
(5541)              --> 000000000001
(5541)           SQL-User-Name set to '000000000001'
rlm_sql (sql): Reserved connection (1)
(5541)           Executing select query: SELECT COUNT(*) FROM edr.failed 
WHERE username = '000000000001'
rlm_sql (sql): Released connection (1)
(5541)           EXPAND %{sql:SELECT COUNT(*) FROM edr.failed WHERE 
username = '%{User-Name}' }
(5541)              --> 45
(5541)           &Tmp-Integer-1 := 45
(5541)           EXPAND EDR req_num:%n req_id:%I MAC %{request:User-Name} 
from relay %{request:Packet-Src-IP-Address} rejected, failed count = 
%{control:Tmp-Integer-1}
(5541)              --> EDR req_num:5541 req_id:151 MAC 000000000001 from 
relay 127.0.0.1 rejected, failed count = 45
(5541)           &Tmp-String-0 := EDR req_num:5541 req_id:151 MAC 
000000000001 from relay 127.0.0.1 rejected, failed count = 45
(5541)         } # update control = noop
(5541)       } # if (Client-Shortname != "L2R")  = noop
(5541)       ... skipping else: Preceding "if" was taken
(5541)       update reply {
(5541)         &Reply-Message += &control:Tmp-String-0 -> 'EDR 
req_num:5541 req_id:151 MAC 000000000001 from relay 127.0.0.1 rejected, 
failed count = 45 '
(5541)         No attributes updated for RHS 
&request:ENDFORCE-RelayAgentAddr
(5541)       } # update reply = noop
(5541)       update control {
(5541)         &Auth-Type := Reject
(5541)       } # update control = noop
(5541)       [reject] = reject
(5541)     } # policy edr_count_and_reject = reject
(5541)   } # post-auth = reject
(5541) Using Post-Auth-Type Reject
(5541) Post-Auth-Type sub-section not found.  Ignoring.
(5541) # Executing group from file /etc/edr_raddb/sites-enabled/default
(5541) EXPAND %{&reply:Reply-Message}
(5541)    --> EDR req_num:5541 req_id:151 MAC 000000000001 from relay 
127.0.0.1 rejected, failed count = 45
(5541) Rejected in post-auth: [000000000001/<via Auth-Type = Reject>] 
(from client localhost port 10) EDR req_num:5541 req_id:151 MAC 
000000000001 from relay 127.0.0.1 rejected, failed count = 45
(5541) EXPAND %{&reply:Reply-Message}
(5541)    --> EDR req_num:5541 req_id:151 MAC 000000000001 from relay 
127.0.0.1 rejected, failed count = 45
(5541) Login incorrect (rlm_sql_db2: HY014: [IBM][CLI Driver] CLI0129E  An 
attempt to allocate a handle failed because there are no more handles to 
allocate. SQLSTATE=HY014): [000000000001/<via Auth-Type = Reject>] (from 
client localhost port 10) EDR req_num:5541 req_id:151 MAC 000000000001 
from relay 127.0.0.1 rejected, failed count = 45
(5541) Sent Access-Reject Id 151 from 127.0.0.1:1812 to 127.0.0.1:30962 
length 0
(5541)   Reply-Message += "EDR req_num:5541 req_id:151 MAC 000000000001 
from relay 127.0.0.1 rejected, failed count = 45 "
(5541) Finished request
(5506) Cleaning up request packet ID 240 with timestamp +338
...
Waking up in 1.9 seconds.
(5672) Cleaning up request packet ID 198 with timestamp +374
Ready to process requests

Michael Wyatt

g4-lisz＠tonarchiv.ch

Alan DeKok

tags

participants (3)