escaping close brace inside "d string is not working

Chinnapaiyan, Nagamani Nagamani.Chinnapaiyan at viasat.com
Thu Dec 6 11:42:50 CET 2018


Hi,

I am trying to send a command to redis db from dhcp server. That command has pool name “{local}:pool” as argument.
Here I need to escape the close brace like below,
        if("%{redis: EXISTS {local\}:pool}" == 1) {
This one should send EXISTS command to redis db with argument “{local}:pool”. But it is sending “{local\}:pool”.

If I remove the \} escaping like below,
        if("%{redis: EXISTS {local}:pool}" == 1) {
this sends only “{local” as argument.

Debug output(for \}):
Thu Dec  6 04:26:23 2018 : Info  : FreeRADIUS Version 4.0.0
Thu Dec  6 04:26:23 2018 : Info  : Copyright 1999-2018 The FreeRADIUS server project and contributors
Thu Dec  6 04:26:23 2018 : Info  : There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Thu Dec  6 04:26:23 2018 : Info  : PARTICULAR PURPOSE
Thu Dec  6 04:26:23 2018 : Info  : You may redistribute copies of FreeRADIUS under the terms of the
Thu Dec  6 04:26:23 2018 : Info  : GNU General Public License
Thu Dec  6 04:26:23 2018 : Info  : For more information about these matters, see the file named COPYRIGHT
Thu Dec  6 04:26:23 2018 : Info  : Starting - reading configuration files ...
Thu Dec  6 04:26:23 2018 : Debug : Including dictionary file "/usr/local/share/freeradius/dictionary"
Thu Dec  6 04:26:23 2018 : Debug : Including dictionary file "/usr/local/etc/raddb/dictionary"
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/radiusd.conf
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/clients.conf
Thu Dec  6 04:26:23 2018 : Debug : Including files in directory "/usr/local/etc/raddb/mods-enabled/"
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/always
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/chap
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/client
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail.log
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/digest
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/dhcpv4
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/eap_inner
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/echo
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/escape
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/exec
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expiration
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expr
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/files
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/linelog
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/logintime
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/mschap
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/pam
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/pap
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/passwd
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radius
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radutmp
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/soh
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/stats
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unix
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unpack
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/utf8
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/mac2ip
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis_ippool
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis
Thu Dec  6 04:26:23 2018 : Debug : Including files in directory "/usr/local/etc/raddb/policy.d/"
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/abfab-tr
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/accounting
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/canonicalization
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/control
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/cui
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/debug
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/dhcp
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/eap
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/filter
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/operator-name
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/time
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/vendor
Thu Dec  6 04:26:23 2018 : Debug : Including files in directory "/usr/local/etc/raddb/sites-enabled/"
Thu Dec  6 04:26:23 2018 : Debug : including configuration file /usr/local/etc/raddb/sites-enabled/dhcp
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary proto_dhcpv4
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "proto_dhcpv4"
Thu Dec  6 04:26:23 2018 : Debug : Parsing security rules to bootstrap UID / GID / chroot / etc.
Thu Dec  6 04:26:23 2018 : Debug : main {
Thu Dec  6 04:26:23 2018 : Debug :   security {
Thu Dec  6 04:26:23 2018 : Debug :     allow_core_dumps = no
Thu Dec  6 04:26:23 2018 : Debug :     allow_vulnerable_openssl = "no"
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   name = radiusd
Thu Dec  6 04:26:23 2018 : Debug :   name = "radiusd"
Thu Dec  6 04:26:23 2018 : Debug :   prefix = "/usr/local"
Thu Dec  6 04:26:23 2018 : Debug :   local_state_dir = "/usr/local/var"
Thu Dec  6 04:26:23 2018 : Debug :   run_dir = "/usr/local/var/run/radiusd"
Thu Dec  6 04:26:23 2018 : Debug : }
Thu Dec  6 04:26:23 2018 : Debug : Parsing main configuration.
Thu Dec  6 04:26:23 2018 : Debug : main {
Thu Dec  6 04:26:23 2018 : Debug :   server dhcp {
Thu Dec  6 04:26:23 2018 : Debug :     namespace = "dhcpv4"
Thu Dec  6 04:26:23 2018 : Debug :     listen {
Thu Dec  6 04:26:23 2018 : Debug :       type = DHCP-Discover
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "proto_dhcpv4_base"
Thu Dec  6 04:26:23 2018 : Debug :       type = DHCP-Request
Thu Dec  6 04:26:23 2018 : Debug :       type = DHCP-Inform
Thu Dec  6 04:26:23 2018 : Debug :       type = DHCP-Release
Thu Dec  6 04:26:23 2018 : Debug :       type = DHCP-Decline
Thu Dec  6 04:26:23 2018 : Debug :       transport = udp
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary proto_dhcpv4_udp
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "proto_dhcpv4_udp"
Thu Dec  6 04:26:23 2018 : Debug :       udp {
Thu Dec  6 04:26:23 2018 : Debug :         ipaddr = 10.43.18.92
Thu Dec  6 04:26:23 2018 : Debug :         port = 67
Thu Dec  6 04:26:23 2018 : Debug :         broadcast = no
Thu Dec  6 04:26:23 2018 : Debug :         networks {
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :         max_packet_size = 4096
Thu Dec  6 04:26:23 2018 : Debug :         max_attributes = 0
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       limit {
Thu Dec  6 04:26:23 2018 : Debug :         idle_timeout = 30.000000
Thu Dec  6 04:26:23 2018 : Debug :         nak_lifetime = 30.000000
Thu Dec  6 04:26:23 2018 : Debug :         max_connections = 1024
Thu Dec  6 04:26:23 2018 : Debug :         max_clients = 256
Thu Dec  6 04:26:23 2018 : Debug :         max_pending_packets = 256
Thu Dec  6 04:26:23 2018 : Debug :         priority {
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Discover = normal
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Request = normal
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Decline = normal
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Release = normal
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Inform = normal
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Lease-Query = low
Thu Dec  6 04:26:23 2018 : Debug :           DHCP-Bulk-Lease-Query = low
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   security {
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   sbin_dir = "/usr/local/sbin"
Thu Dec  6 04:26:23 2018 : Debug :   logdir = "/usr/local/var/log/radius"
Thu Dec  6 04:26:23 2018 : Debug :   libdir = "/usr/local/lib"
Thu Dec  6 04:26:23 2018 : Debug :   radacctdir = "/usr/local/var/log/radius/radacct"
Thu Dec  6 04:26:23 2018 : Debug :   reverse_lookups = no
Thu Dec  6 04:26:23 2018 : Debug :   reverse_lookups = no
Thu Dec  6 04:26:23 2018 : Debug :   hostname_lookups = yes
Thu Dec  6 04:26:23 2018 : Debug :   hostname_lookups = yes
Thu Dec  6 04:26:23 2018 : Debug :   max_request_time = 30
Thu Dec  6 04:26:23 2018 : Debug :   max_request_time = 30
Thu Dec  6 04:26:23 2018 : Debug :   pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Thu Dec  6 04:26:23 2018 : Debug :   debug_level = 0
Thu Dec  6 04:26:23 2018 : Debug :   log {
Thu Dec  6 04:26:23 2018 : Debug :     colourise = yes
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   resources {
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   thread pool {
Thu Dec  6 04:26:23 2018 : Debug :     num_networks = 1
Thu Dec  6 04:26:23 2018 : Debug :     num_networks = 1
Thu Dec  6 04:26:23 2018 : Debug :     num_workers = 4
Thu Dec  6 04:26:23 2018 : Debug :     num_workers = 4
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug : }
Thu Dec  6 04:26:23 2018 : Info  : Switching to configured log settings
Thu Dec  6 04:26:23 2018 : Debug : radiusd: #### Loading Clients ####
Thu Dec  6 04:26:23 2018 : Debug :   client localhost {
Thu Dec  6 04:26:23 2018 : Debug :     ipaddr = 127.0.0.1
Thu Dec  6 04:26:23 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 04:26:23 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 04:26:23 2018 : Debug :     proto = "*"
Thu Dec  6 04:26:23 2018 : Debug :     limit {
Thu Dec  6 04:26:23 2018 : Debug :       max_connections = 16
Thu Dec  6 04:26:23 2018 : Debug :       lifetime = 0
Thu Dec  6 04:26:23 2018 : Debug :       idle_timeout = 30
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   client localhost_ipv6 {
Thu Dec  6 04:26:23 2018 : Debug :     ipv6addr = ::1
Thu Dec  6 04:26:23 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 04:26:23 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 04:26:23 2018 : Debug :     limit {
Thu Dec  6 04:26:23 2018 : Debug :       max_connections = 16
Thu Dec  6 04:26:23 2018 : Debug :       lifetime = 0
Thu Dec  6 04:26:23 2018 : Debug :       idle_timeout = 30
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :   client private-network-1 {
Thu Dec  6 04:26:23 2018 : Debug :     ipaddr = 10.43.18.0/24
Thu Dec  6 04:26:23 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 04:26:23 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 04:26:23 2018 : Debug :     limit {
Thu Dec  6 04:26:23 2018 : Debug :       max_connections = 16
Thu Dec  6 04:26:23 2018 : Debug :       lifetime = 0
Thu Dec  6 04:26:23 2018 : Debug :       idle_timeout = 30
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Info  : Debugger not attached
Thu Dec  6 04:26:23 2018 : Debug : #### Bootstrapping listeners ####
Thu Dec  6 04:26:23 2018 : Debug : #### Bootstrapping modules ####
Thu Dec  6 04:26:23 2018 : Debug :  modules {
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_always"
Thu Dec  6 04:26:23 2018 : Debug :     always reject {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "reject"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always fail {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "fail"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always ok {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "ok"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always handled {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "handled"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always invalid {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "invalid"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always userlock {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "userlock"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always notfound {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "notfound"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always noop {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "noop"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     always updated {
Thu Dec  6 04:26:23 2018 : Debug :       rcode = "updated"
Thu Dec  6 04:26:23 2018 : Debug :       simulcount = 0
Thu Dec  6 04:26:23 2018 : Debug :       mpp = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_attr_filter
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_attr_filter"
Thu Dec  6 04:26:23 2018 : Debug :     attr_filter attr_filter.pre-proxy {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy"
Thu Dec  6 04:26:23 2018 : Debug :       relaxed = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     attr_filter attr_filter.post-proxy {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy"
Thu Dec  6 04:26:23 2018 : Debug :       relaxed = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     attr_filter attr_filter.access_reject {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject"
Thu Dec  6 04:26:23 2018 : Debug :       relaxed = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     attr_filter attr_filter.access_challenge {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge"
Thu Dec  6 04:26:23 2018 : Debug :       relaxed = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     attr_filter attr_filter.accounting_response {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response"
Thu Dec  6 04:26:23 2018 : Debug :       relaxed = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_cache
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_cache"
Thu Dec  6 04:26:23 2018 : Debug :     cache cache_eap {
Thu Dec  6 04:26:23 2018 : Debug :       driver = "rlm_cache_rbtree"
Thu Dec  6 04:26:23 2018 : Debug :       ttl = 15
Thu Dec  6 04:26:23 2018 : Debug :       max_entries = 0
Thu Dec  6 04:26:23 2018 : Debug :       epoch = 0
Thu Dec  6 04:26:23 2018 : Debug :       add_stats = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_chap
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_chap"
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_client"
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_detail
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_detail"
Thu Dec  6 04:26:23 2018 : Debug :     detail {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/detail-%Y-%m-%d"
Thu Dec  6 04:26:23 2018 : Debug :       header = "%t"
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       locking = no
Thu Dec  6 04:26:23 2018 : Debug :       escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       log_packet_header = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     detail auth_log {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/auth-detail-%Y-%m-%d"
Thu Dec  6 04:26:23 2018 : Debug :       header = "%t"
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       locking = no
Thu Dec  6 04:26:23 2018 : Debug :       escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       log_packet_header = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     detail reply_log {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/reply-detail-%Y-%m-%d"
Thu Dec  6 04:26:23 2018 : Debug :       header = "%t"
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       locking = no
Thu Dec  6 04:26:23 2018 : Debug :       escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       log_packet_header = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     detail pre_proxy_log {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/pre-proxy-detail-%Y-%m-%d"
Thu Dec  6 04:26:23 2018 : Debug :       header = "%t"
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       locking = no
Thu Dec  6 04:26:23 2018 : Debug :       escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       log_packet_header = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     detail post_proxy_log {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/post-proxy-detail-%Y-%m-%d"
Thu Dec  6 04:26:23 2018 : Debug :       header = "%t"
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       locking = no
Thu Dec  6 04:26:23 2018 : Debug :       escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       log_packet_header = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_digest
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_digest"
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_dhcpv4"
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_eap
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_eap"
Thu Dec  6 04:26:23 2018 : Debug :     eap inner-eap {
Thu Dec  6 04:26:23 2018 : Debug :       default_eap_type = mschapv2
Thu Dec  6 04:26:23 2018 : Debug :       type = md5
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_eap_md5
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_eap_md5"
Thu Dec  6 04:26:23 2018 : Debug :       type = gtc
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_eap_gtc
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_eap_gtc"
Thu Dec  6 04:26:23 2018 : Debug :       gtc {
Thu Dec  6 04:26:23 2018 : Debug :         challenge = "Password: "
Thu Dec  6 04:26:23 2018 : Debug :         auth_type = PAP
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       type = mschapv2
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_eap_mschapv2
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_eap_mschapv2"
Thu Dec  6 04:26:23 2018 : Debug :       mschapv2 {
Thu Dec  6 04:26:23 2018 : Debug :         with_ntdomain_hack = no
Thu Dec  6 04:26:23 2018 : Debug :         auth_type = mschap
Thu Dec  6 04:26:23 2018 : Debug :         send_error = no
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       type = tls
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_eap_tls
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_eap_tls"
Thu Dec  6 04:26:23 2018 : Debug :       tls {
Thu Dec  6 04:26:23 2018 : Debug :         tls = "tls-peer"
Thu Dec  6 04:26:23 2018 : Debug :         require_client_cert = yes
Thu Dec  6 04:26:23 2018 : Debug :         include_length = yes
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       ignore_unknown_eap_types = no
Thu Dec  6 04:26:23 2018 : Debug :       cisco_accounting_username_bug = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_exec"
Thu Dec  6 04:26:23 2018 : Debug :     exec echo {
Thu Dec  6 04:26:23 2018 : Debug :       wait = yes
Thu Dec  6 04:26:23 2018 : Debug :       program = "/bin/echo %{User-Name}"
Thu Dec  6 04:26:23 2018 : Debug :       input_pairs = "request"
Thu Dec  6 04:26:23 2018 : Debug :       output_pairs = "reply"
Thu Dec  6 04:26:23 2018 : Debug :       shell_escape = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_escape"
Thu Dec  6 04:26:23 2018 : Debug :     escape {
Thu Dec  6 04:26:23 2018 : Debug :       safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     exec {
Thu Dec  6 04:26:23 2018 : Debug :       wait = no
Thu Dec  6 04:26:23 2018 : Debug :       input_pairs = "request"
Thu Dec  6 04:26:23 2018 : Debug :       shell_escape = yes
Thu Dec  6 04:26:23 2018 : Debug :       timeout = 10
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_expiration
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_expiration"
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_expr"
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_files
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_files"
Thu Dec  6 04:26:23 2018 : Debug :     files {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/files/authorize"
Thu Dec  6 04:26:23 2018 : Debug :       acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting"
Thu Dec  6 04:26:23 2018 : Debug :       preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy"
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_linelog"
Thu Dec  6 04:26:23 2018 : Debug :     linelog {
Thu Dec  6 04:26:23 2018 : Debug :       destination = "file"
Thu Dec  6 04:26:23 2018 : Debug :       delimiter = " "
Thu Dec  6 04:26:23 2018 : Debug :       file {
Thu Dec  6 04:26:23 2018 : Debug :         filename = "/usr/local/var/log/radius/linelog"
Thu Dec  6 04:26:23 2018 : Debug :         permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :         escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       syslog {
Thu Dec  6 04:26:23 2018 : Debug :         severity = "info"
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       unix {
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       tcp {
Thu Dec  6 04:26:23 2018 : Debug :         port = 514
Thu Dec  6 04:26:23 2018 : Debug :         timeout = 2.000000
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       udp {
Thu Dec  6 04:26:23 2018 : Debug :         port = 514
Thu Dec  6 04:26:23 2018 : Debug :         timeout = 2.000000
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     linelog log_accounting {
Thu Dec  6 04:26:23 2018 : Debug :       destination = "file"
Thu Dec  6 04:26:23 2018 : Debug :       delimiter = " "
Thu Dec  6 04:26:23 2018 : Debug :       file {
Thu Dec  6 04:26:23 2018 : Debug :         filename = "/usr/local/var/log/radius/linelog-accounting"
Thu Dec  6 04:26:23 2018 : Debug :         permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :         escape_filenames = no
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       syslog {
Thu Dec  6 04:26:23 2018 : Debug :         severity = "info"
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       unix {
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       tcp {
Thu Dec  6 04:26:23 2018 : Debug :         timeout = 1000.000000
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       udp {
Thu Dec  6 04:26:23 2018 : Debug :         timeout = 1000.000000
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_logintime
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_logintime"
Thu Dec  6 04:26:23 2018 : Debug :     logintime {
Thu Dec  6 04:26:23 2018 : Debug :       minimum_timeout = 60
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_mschap"
Thu Dec  6 04:26:23 2018 : Debug :     mschap {
Thu Dec  6 04:26:23 2018 : Debug :       use_mppe = yes
Thu Dec  6 04:26:23 2018 : Debug :       require_encryption = no
Thu Dec  6 04:26:23 2018 : Debug :       require_strong = no
Thu Dec  6 04:26:23 2018 : Debug :       with_ntdomain_hack = yes
Thu Dec  6 04:26:23 2018 : Debug :       passchange {
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       allow_retry = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     exec ntlm_auth {
Thu Dec  6 04:26:23 2018 : Debug :       wait = yes
Thu Dec  6 04:26:23 2018 : Debug :       program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap
:User-Name} --password=%{User-Password}"
Thu Dec  6 04:26:23 2018 : Debug :       shell_escape = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_pam
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_pam"
Thu Dec  6 04:26:23 2018 : Debug :     pam {
Thu Dec  6 04:26:23 2018 : Debug :       pam_auth = "radiusd"
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_pap
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_pap"
Thu Dec  6 04:26:23 2018 : Debug :     pap {
Thu Dec  6 04:26:23 2018 : Debug :       normalise = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_passwd
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_passwd"
Thu Dec  6 04:26:23 2018 : Debug :     passwd etc_passwd {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/etc/passwd"
Thu Dec  6 04:26:23 2018 : Debug :       format = "*User-Name:Crypt-Password:"
Thu Dec  6 04:26:23 2018 : Debug :       delimiter = ":"
Thu Dec  6 04:26:23 2018 : Debug :       ignore_nislike = no
Thu Dec  6 04:26:23 2018 : Debug :       ignore_empty = yes
Thu Dec  6 04:26:23 2018 : Debug :       allow_multiple_keys = no
Thu Dec  6 04:26:23 2018 : Debug :       hash_size = 100
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_radius
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_radius"
Thu Dec  6 04:26:23 2018 : Debug :     radius {
Thu Dec  6 04:26:23 2018 : Debug :       transport = udp
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_radius_udp
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_radius_udp"
Thu Dec  6 04:26:23 2018 : Debug :       udp {
Thu Dec  6 04:26:23 2018 : Debug :         ipaddr = 127.0.0.1
Thu Dec  6 04:26:23 2018 : Debug :         port = 1812
Thu Dec  6 04:26:23 2018 : Debug :         secret = "testing123"
Thu Dec  6 04:26:23 2018 : Debug :         max_packet_size = 4096
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       type = Access-Request
Thu Dec  6 04:26:23 2018 : Debug :       type = Accounting-Request
Thu Dec  6 04:26:23 2018 : Debug :       status_checks {
Thu Dec  6 04:26:23 2018 : Debug :         type = Status-Server
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       max_connections = 32
Thu Dec  6 04:26:23 2018 : Debug :       max_attributes = 255
Thu Dec  6 04:26:23 2018 : Debug :       connection {
Thu Dec  6 04:26:23 2018 : Debug :         connect_timeout = 5.000000
Thu Dec  6 04:26:23 2018 : Debug :         reconnect_delay = 5.000000
Thu Dec  6 04:26:23 2018 : Debug :         idle_timeout = 5.000000
Thu Dec  6 04:26:23 2018 : Debug :         zombie_period = 10.000000
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       Access-Request {
Thu Dec  6 04:26:23 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_count = 2
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       Accounting-Request {
Thu Dec  6 04:26:23 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_count = 5
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :       Status-Server {
Thu Dec  6 04:26:23 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_count = 5
Thu Dec  6 04:26:23 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_radutmp
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_radutmp"
Thu Dec  6 04:26:23 2018 : Debug :     radutmp {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/radutmp"
Thu Dec  6 04:26:23 2018 : Debug :       username = "%{User-Name}"
Thu Dec  6 04:26:23 2018 : Debug :       case_sensitive = yes
Thu Dec  6 04:26:23 2018 : Debug :       check_with_nas = yes
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 384
Thu Dec  6 04:26:23 2018 : Debug :       caller_id = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_soh
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_soh"
Thu Dec  6 04:26:23 2018 : Debug :     soh {
Thu Dec  6 04:26:23 2018 : Debug :       dhcp = yes
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :     radutmp sradutmp {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/var/log/radius/sradutmp"
Thu Dec  6 04:26:23 2018 : Debug :       username = "%{User-Name}"
Thu Dec  6 04:26:23 2018 : Debug :       case_sensitive = yes
Thu Dec  6 04:26:23 2018 : Debug :       check_with_nas = yes
Thu Dec  6 04:26:23 2018 : Debug :       permissions = 420
Thu Dec  6 04:26:23 2018 : Debug :       caller_id = no
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_stats
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_stats"
Thu Dec  6 04:26:23 2018 : Debug :     stats {
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_unix
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_unix"
Thu Dec  6 04:26:23 2018 : Debug :     unix {
Thu Dec  6 04:26:23 2018 : Debug :       radwtmp = "/usr/local/var/log/radius/radwtmp"
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug : Creating attribute Unix-Group
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_unpack
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_unpack"
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_utf8"
Thu Dec  6 04:26:23 2018 : Debug :     passwd mac2ip {
Thu Dec  6 04:26:23 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/passwd/mac2ip"
Thu Dec  6 04:26:23 2018 : Debug :       format = "*DHCP-Client-Hardware-Address:=DHCP-Your-IP-Address"
Thu Dec  6 04:26:23 2018 : Debug :       delimiter = ","
Thu Dec  6 04:26:23 2018 : Debug :       ignore_nislike = yes
Thu Dec  6 04:26:23 2018 : Debug :       ignore_empty = yes
Thu Dec  6 04:26:23 2018 : Debug :       allow_multiple_keys = no
Thu Dec  6 04:26:23 2018 : Debug :       hash_size = 100
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : libfreeradius-redis: libhiredis version: 0.12.1
Thu Dec  6 04:26:23 2018 : Debug : Loading dictionary rlm_redis_ippool
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_redis_ippool"
Thu Dec  6 04:26:23 2018 : Debug :     redis_ippool {
Thu Dec  6 04:26:23 2018 : Debug :       copy_on_update = yes
Thu Dec  6 04:26:23 2018 : Debug :       redis {
Thu Dec  6 04:26:23 2018 : Debug :         server = "10.43.16.224"
Thu Dec  6 04:26:23 2018 : Debug :         port = 6379
Thu Dec  6 04:26:23 2018 : Debug :         database = 0
Thu Dec  6 04:26:23 2018 : Debug :         max_nodes = 20
Thu Dec  6 04:26:23 2018 : Debug :         max_alt = 3
Thu Dec  6 04:26:23 2018 : Debug :         max_redirects = 2
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Info  : libfreeradius-redis: libhiredis version: 0.12.1
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_redis"
Thu Dec  6 04:26:23 2018 : Debug :     redis {
Thu Dec  6 04:26:23 2018 : Debug :       server = "10.43.16.224"
Thu Dec  6 04:26:23 2018 : Debug :       port = 6379
Thu Dec  6 04:26:23 2018 : Debug :       database = 0
Thu Dec  6 04:26:23 2018 : Debug :       max_nodes = 20
Thu Dec  6 04:26:23 2018 : Debug :       max_alt = 3
Thu Dec  6 04:26:23 2018 : Debug :       max_redirects = 2
Thu Dec  6 04:26:23 2018 : Debug :     }
Thu Dec  6 04:26:23 2018 : Debug :   instantiate {
Thu Dec  6 04:26:23 2018 : Debug :   }
Thu Dec  6 04:26:23 2018 : Debug :  } # modules
Thu Dec  6 04:26:23 2018 : Debug : #### Instantiating listeners ####
Thu Dec  6 04:26:23 2018 : Debug : Compiling policies in server dhcp { ... }
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Discover {...}
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Request {...}
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Decline {...}
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Inform {...}
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Release {...}
Thu Dec  6 04:26:23 2018 : Debug : compiling - recv DHCP-Lease-Query {...}
Thu Dec  6 04:26:23 2018 : Debug : #### Instantiating modules ####
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "attr_filter.access_challenge"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "attr_filter.access_reject"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_reject
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "attr_filter.accounting_response"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "attr_filter.post-proxy"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "attr_filter.pre-proxy"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "auth_log"
Thu Dec  6 04:26:23 2018 : Debug : rlm_detail (auth_log) - 'User-Password' suppressed, will not appear in detail output
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "cache_eap"
Thu Dec  6 04:26:23 2018 : Info  : Loaded module "rlm_cache_rbtree"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "detail"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "etc_passwd"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "expiration"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "fail"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "files"
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/authorize
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/accounting
Thu Dec  6 04:26:23 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/pre-proxy
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "handled"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "inner-eap"
Thu Dec  6 04:26:23 2018 : Debug :       tls-config tls-peer {
Thu Dec  6 04:26:23 2018 : Debug :         auto_chain = yes
Thu Dec  6 04:26:23 2018 : Debug :         chain {
Thu Dec  6 04:26:23 2018 : Debug :           format = pem
Thu Dec  6 04:26:23 2018 : Debug :           certificate_file = "/usr/local/etc/raddb/certs/rsa/server.pem"
Thu Dec  6 04:26:23 2018 : Debug :           private_key_password = <<< secret >>>
Thu Dec  6 04:26:23 2018 : Debug :           private_key_file = "/usr/local/etc/raddb/certs/rsa/server.key"
Thu Dec  6 04:26:23 2018 : Debug :           ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
Thu Dec  6 04:26:23 2018 : Debug :           verify_mode = hard
Thu Dec  6 04:26:23 2018 : Debug :           include_root_ca = no
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :         verify_depth = 0
Thu Dec  6 04:26:23 2018 : Debug :         ca_path = "/usr/local/etc/raddb/certs"
Thu Dec  6 04:26:23 2018 : Debug :         ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
Thu Dec  6 04:26:23 2018 : Debug :         dh_file = "/usr/local/etc/raddb/certs/dh"
Thu Dec  6 04:26:23 2018 : Debug :         fragment_size = 16384
Thu Dec  6 04:26:23 2018 : Debug :         check_crl = no
Thu Dec  6 04:26:23 2018 : Debug :         cipher_server_preference = yes
Thu Dec  6 04:26:23 2018 : Debug :         allow_renegotiation = no
Thu Dec  6 04:26:23 2018 : Debug :         ecdh_curve = "prime256v1"
Thu Dec  6 04:26:23 2018 : Debug :         tls_min_version = 1.000000
Thu Dec  6 04:26:23 2018 : Debug :         cache {
Thu Dec  6 04:26:23 2018 : Debug :           lifetime = 86400
Thu Dec  6 04:26:23 2018 : Debug :           verify = no
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :         verify {
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :         ocsp {
Thu Dec  6 04:26:23 2018 : Debug :           enable = no
Thu Dec  6 04:26:23 2018 : Debug :           override_cert_url = no
Thu Dec  6 04:26:23 2018 : Debug :           use_nonce = yes
Thu Dec  6 04:26:23 2018 : Debug :           timeout = 0
Thu Dec  6 04:26:23 2018 : Debug :           softfail = no
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :         staple {
Thu Dec  6 04:26:23 2018 : Debug :           enable = no
Thu Dec  6 04:26:23 2018 : Debug :           override_cert_url = no
Thu Dec  6 04:26:23 2018 : Debug :           use_nonce = yes
Thu Dec  6 04:26:23 2018 : Debug :           timeout = 0
Thu Dec  6 04:26:23 2018 : Debug :           softfail = no
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "invalid"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "linelog"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "log_accounting"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "logintime"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "mac2ip"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "mschap"
Thu Dec  6 04:26:23 2018 : Debug : mschap: using internal authentication
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "noop"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "notfound"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "ok"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "pam"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "post_proxy_log"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "pre_proxy_log"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "radius"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "redis"
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Initialising connection pool
Thu Dec  6 04:26:23 2018 : Debug :       pool {
Thu Dec  6 04:26:23 2018 : Debug :         start = 4
Thu Dec  6 04:26:23 2018 : Debug :         min = 1
Thu Dec  6 04:26:23 2018 : Debug :         max = 4
Thu Dec  6 04:26:23 2018 : Debug :         max_pending = 0
Thu Dec  6 04:26:23 2018 : Debug :         spare = 1
Thu Dec  6 04:26:23 2018 : Debug :         uses = 0
Thu Dec  6 04:26:23 2018 : Debug :         lifetime = 86400
Thu Dec  6 04:26:23 2018 : Debug :         cleanup_interval = 300
Thu Dec  6 04:26:23 2018 : Debug :         idle_timeout = 600
Thu Dec  6 04:26:23 2018 : Debug :         connect_timeout = 3.000000
Thu Dec  6 04:26:23 2018 : Debug :         held_trigger_min = 0.000000
Thu Dec  6 04:26:23 2018 : Debug :         held_trigger_max = 0.500000
Thu Dec  6 04:26:23 2018 : Debug :         retry_delay = 30
Thu Dec  6 04:26:23 2018 : Debug :         spread = no
Thu Dec  6 04:26:23 2018 : Debug :       }
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (2), 1 of 2 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (3), 1 of 1 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Reserved connection (3)
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis): Bootstrap server "10.43.16.224" returned: ERR This instance has cluster
support disabled
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Released connection (3)
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "redis_ippool"
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Initialising connection pool
Thu Dec  6 04:26:23 2018 : Debug :         pool {
Thu Dec  6 04:26:23 2018 : Debug :           start = 0
Thu Dec  6 04:26:23 2018 : Debug :           min = 4
Thu Dec  6 04:26:23 2018 : Debug :           max = 4
Thu Dec  6 04:26:23 2018 : Debug :           max_pending = 0
Thu Dec  6 04:26:23 2018 : Debug :           spare = 1
Thu Dec  6 04:26:23 2018 : Debug :           uses = 0
Thu Dec  6 04:26:23 2018 : Debug :           lifetime = 0
Thu Dec  6 04:26:23 2018 : Debug :           cleanup_interval = 30
Thu Dec  6 04:26:23 2018 : Debug :           idle_timeout = 60
Thu Dec  6 04:26:23 2018 : Debug :           connect_timeout = 3.000000
Thu Dec  6 04:26:23 2018 : Debug :           held_trigger_min = 0.000000
Thu Dec  6 04:26:23 2018 : Debug :           held_trigger_max = 0.500000
Thu Dec  6 04:26:23 2018 : Debug :           retry_delay = 30
Thu Dec  6 04:26:23 2018 : Debug :           spread = no
Thu Dec  6 04:26:23 2018 : Debug :         }
Thu Dec  6 04:26:23 2018 : Warn  : rlm_redis (redis) [1] - Ignoring "spare = 1", forcing to "spare = 0"
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - 0 of 0 connections in use.  You  may need to increase "spare"
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Reserved connection (0)
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Released connection (0)
Thu Dec  6 04:26:23 2018 : Info  : rlm_redis (redis) [1] - Need 3 more connections to reach min connections (4)
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
Thu Dec  6 04:26:23 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "reject"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "reply_log"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "stats"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "updated"
Thu Dec  6 04:26:23 2018 : Debug : Instantiating module "userlock"
Thu Dec  6 04:26:23 2018 : Debug : [1] radius - Connection initialising
Thu Dec  6 04:26:23 2018 : Debug : [1] radius - Connection initialised
Thu Dec  6 04:26:23 2018 : Debug : Scheduler created in single-threaded mode
Thu Dec  6 04:26:23 2018 : Debug : #### Opening listener interfaces ####
Thu Dec  6 04:26:23 2018 : Debug : Listening on dhcpv4 address proto_dhcpv4_udp server 10.43.18.92 port 67 bound to virtual s
erver dhcp
Thu Dec  6 04:26:23 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 04:26:23 2018 : Debug : radius - Connection open - proto udp local 0.0.0.0 port 37614 remote 127.0.0.1 port 1812
Thu Dec  6 04:26:23 2018 : Debug : radius - Allocated Status-Server ID 0 for status checks on connection proto udp local 0.0.
0.0 port 37614 remote 127.0.0.1 port 1812
Thu Dec  6 04:26:23 2018 : Debug : radius - Setting idle timeout to +5.000000 for connection proto udp local 0.0.0.0 port 376
14 remote 127.0.0.1 port 1812
Thu Dec  6 04:26:23 2018 : Debug : [1] radius - Connection established
Thu Dec  6 04:26:23 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 04:26:23 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 04:26:28 2018 : Debug : radius - Idle timeout for connection proto udp local 0.0.0.0 port 37614 remote 127.0.0.1 p
ort 1812
Thu Dec  6 04:26:28 2018 : Debug : [1] radius - Closing connection (18)
Thu Dec  6 04:26:28 2018 : Debug : radius - Connection closed - proto udp local 0.0.0.0 port 37614 remote 127.0.0.1 port 1812
Thu Dec  6 04:26:28 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:32 2018 : Debug : proto_dhcpv4_udp - Received DHCP-Discover XID 00000000 length 304 proto_dhcpv4_udp server
10.43.18.92 port 67
Thu Dec  6 04:26:32 2018 : Debug : Network received packet size 304
Thu Dec  6 04:26:32 2018 : Debug : Resetting worker 30 cleanup timer to +0s
Thu Dec  6 04:26:32 2018 : Debug : (0)  running request
(0)  Thu Dec  6 04:26:32 2018 : Debug : Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Opcode = Client-Message
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hardware-Type = Ethernet
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hardware-Address-Length = 6
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hop-Count = 1
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Transaction-Id = 0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Number-of-Seconds = 0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Flags = 0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Client-IP-Address = 127.0.0.1
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Your-IP-Address = 0.0.0.0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Server-IP-Address = 0.0.0.0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Gateway-IP-Address = 127.0.0.1
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:01
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Message-Type = DHCP-Discover
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Subnet-Mask
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Broadcast-Address
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Time-Offset
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Router-Address
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name-Server
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Hostname
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Subscriber-Id = "00a0bc000001 at aut.res.viasat.com"
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Relay-Remote-Id = 0x00a0bc000001
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Relay-Circuit-Id = 0x000000222066
(0)  Thu Dec  6 04:26:32 2018 : Debug : Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp
(0)  Thu Dec  6 04:26:32 2018 : Debug : recv DHCP-Discover {
(0)  Thu Dec  6 04:26:32 2018 : Debug :   update reply {
(0)  Thu Dec  6 04:26:32 2018 : Debug :     DHCP-Message-Type = DHCP-Offer
(0)  Thu Dec  6 04:26:32 2018 : Debug :   } # update reply (noop)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   update reply {
(0)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-Subnet-Mask = 255.255.255.0
(0)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-Router-Address = 10.43.18.92
(0)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-IP-Address-Lease-Time = 900
(0)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-DHCP-Server-Identifier = 10.43.18.92
(0)  Thu Dec  6 04:26:32 2018 : Debug :   } # update reply (noop)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   update control {
(0)  Thu Dec  6 04:26:32 2018 : Debug :     &Pool-Name := "local"
(0)  Thu Dec  6 04:26:32 2018 : Debug :   } # update control (noop)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Allocating lease from pool "local", to "00:a0:bc:00:00:01", expires
in 900s
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Reserved connection (1)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - [1] >>> Sending command(s) to 10.43.16.224:6379
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - [1] <<< Returned: success
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Released connection (1)
(0)  Thu Dec  6 04:26:32 2018 : Info  :   redis_ippool - Need 2 more connections to reach min connections (4)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Opening additional connection (2), 1 of 2 pending slots used
Thu Dec  6 04:26:32 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.24.0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 463
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - IP address lease allocated
(0)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool (updated)
(0)  Thu Dec  6 04:26:32 2018 : Debug :   ok (ok)
(0)  Thu Dec  6 04:26:32 2018 : Debug : } # recv DHCP-Discover (updated)
(0)  Thu Dec  6 04:26:32 2018 : Debug : Sent DHCP-Offer XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Message-Type = DHCP-Offer
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Subnet-Mask = 255.255.255.0
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Router-Address = 10.43.18.92
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-IP-Address-Lease-Time := 463
(0)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
Thu Dec  6 04:26:32 2018 : Debug : (0)  done request
Thu Dec  6 04:26:32 2018 : Debug : (0)  finished request.
Thu Dec  6 04:26:32 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:32 2018 : Debug : Reply will be unicast to CIADDR from original packet.
Thu Dec  6 04:26:32 2018 : Debug : proto_dhcpv4_udp - cleaning up ID 1
Thu Dec  6 04:26:32 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:32 2018 : Debug : proto_dhcpv4_udp - Received DHCP-Request XID 00000000 length 325 proto_dhcpv4_udp server 1
0.43.18.92 port 67
Thu Dec  6 04:26:32 2018 : Debug : Network received packet size 325
Thu Dec  6 04:26:32 2018 : Debug : Resetting worker 30 cleanup timer to +0s
Thu Dec  6 04:26:32 2018 : Debug : (1)  running request
(1)  Thu Dec  6 04:26:32 2018 : Debug : Received DHCP-Request XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Opcode = Client-Message
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hardware-Type = Ethernet
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hardware-Address-Length = 6
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Hop-Count = 1
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Transaction-Id = 0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Number-of-Seconds = 0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Flags = 0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Client-IP-Address = 127.0.0.1
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Your-IP-Address = 0.0.0.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Server-IP-Address = 0.0.0.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Gateway-IP-Address = 127.0.0.1
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:01
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Requested-IP-Address = 192.168.24.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Message-Type = DHCP-Request
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Subnet-Mask
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Broadcast-Address
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Time-Offset
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Router-Address
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name-Server
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Hostname
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Client-Identifier = 0x01afac00000000
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Subscriber-Id = "00a0bc000001 at aut.res.viasat.com"
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Relay-Remote-Id = 0x00a0bc000001
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Relay-Circuit-Id = 0x000000222066
(1)  Thu Dec  6 04:26:32 2018 : Debug : Running 'recv DHCP-Request' from file /usr/local/etc/raddb/sites-enabled/dhcp
(1)  Thu Dec  6 04:26:32 2018 : Debug : recv DHCP-Request {
(1)  Thu Dec  6 04:26:32 2018 : Debug :   update reply {
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-Message-Type = DHCP-Ack
(1)  Thu Dec  6 04:26:32 2018 : Debug :   } # update reply (noop)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   update reply {
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-Subnet-Mask = 255.255.255.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-Router-Address = 10.43.18.92
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-IP-Address-Lease-Time = 900
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)  Thu Dec  6 04:26:32 2018 : Debug :   } # update reply (noop)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   update control {
(1)  Thu Dec  6 04:26:32 2018 : Debug :     &Pool-Name := "local"
(1)  Thu Dec  6 04:26:32 2018 : Debug :   } # update control (noop)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Allocating lease from pool "local", to "00:a0:bc:00:00:01", expires
in 900s
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Reserved connection (2)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - [1] >>> Sending command(s) to 10.43.16.224:6379
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - [1] <<< Returned: success
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - Released connection (2)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.24.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 463
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool - IP address lease allocated
(1)  Thu Dec  6 04:26:32 2018 : Debug :   redis_ippool (updated)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   if (updated) {
(1)  Thu Dec  6 04:26:32 2018 : Debug :     update reply {
(1)  Thu Dec  6 04:26:32 2018 : Debug :       EXPAND %{control:Pool-Name}
(1)  Thu Dec  6 04:26:32 2018 : Debug :         --> local
(1)  Thu Dec  6 04:26:32 2018 : Debug :       Reserved connection (3)
(1)  Thu Dec  6 04:26:32 2018 : Debug :       [1] >>> Sending command(s) to 10.43.16.224:6379
(1)  Thu Dec  6 04:26:32 2018 : Debug :       Executing command: GET
(1)  Thu Dec  6 04:26:32 2018 : Debug :       With arguments
(1)  Thu Dec  6 04:26:32 2018 : Debug :         [1] local:option
(1)  Thu Dec  6 04:26:32 2018 : Debug :       [1] <<< Returned: success
(1)  Thu Dec  6 04:26:32 2018 : Debug :       Released connection (3)
(1)  Thu Dec  6 04:26:32 2018 : Debug :       EXPAND %{redis: GET %{control:Pool-Name}:option}
(1)  Thu Dec  6 04:26:32 2018 : Debug :             (%{redis: GET local:option})
(1)  Thu Dec  6 04:26:32 2018 : Debug :         --> 010300a0bc0209555400000000000007030e5554000000000000030703070016041155545
f332e372e332e372e32322e62696e05040a4fff0f0c0200010e010014530100020103110500440044070043004301000201030606c0a86400180700500050
01010201060a000000080101020106ac1000000c0101020106c0a80000100101020106a9fe00001001010201067f00000008330c555432000000000000002
9083b0e55543200000000000307030600003c115554325f332e372e332e362e302e62696e3d040a4fff06
(1)  Thu Dec  6 04:26:32 2018 : Debug :       EXPAND %{bin:%{redis: GET %{control:Pool-Name}:option}}
(1)  Thu Dec  6 04:26:32 2018 : Debug :             (%{bin:010300a0bc0209555400000000000007030e555400000000000003070307001604
1155545f332e372e332e372e32322e62696e05040a4fff0f0c0200010e010014530100020103110500440044070043004301000201030606c0a8640018070
050005001010201060a000000080101020106ac1000000c0101020106c0a80000100101020106a9fe00001001010201067f00000008330c55543200000000
00000029083b0e55543200000000000307030600003c115554325f332e372e332e362e302e62696e3d040a4fff06})
(1)  Thu Dec  6 04:26:32 2018 : Debug :         --> 0x010300a0bc0209555400000000000007030e55540000000000000307030700160411555
45f332e372e332e372e32322e62696e05040a4fff0f0c0200010e010014530100020103110500440044070043004301000201030606c0a864001807005000
5001010201060a000000080101020106ac1000000c0101020106c0a80000100101020106a9fe00001001010201067f00000008330c5554320000000000000
029083b0e55543200000000000307030600003c115554325f332e372e332e362e302e62696e3d040a4fff06
(1)  Thu Dec  6 04:26:32 2018 : Debug :       &DHCP-Vendor = 0x010300a0bc0209555400000000000007030e55540000000000000307030700
16041155545f332e372e332e372e32322e62696e05040a4fff0f0c0200010e010014530100020103110500440044070043004301000201030606c0a864001
8070050005001010201060a000000080101020106ac1000000c0101020106c0a80000100101020106a9fe00001001010201067f00000008330c5554320000
000000000029083b0e55543200000000000307030600003c115554325f332e372e332e362e302e62696e3d040a4fff06
(1)  Thu Dec  6 04:26:32 2018 : Debug :     } # update reply (noop)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   } # if (updated) (noop)
(1)  Thu Dec  6 04:26:32 2018 : Debug :   ok (ok)
(1)  Thu Dec  6 04:26:32 2018 : Debug : } # recv DHCP-Request (updated)
(1)  Thu Dec  6 04:26:32 2018 : Debug : Sent DHCP-Ack XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Message-Type = DHCP-Ack
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Subnet-Mask = 255.255.255.0
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Router-Address = 10.43.18.92
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-IP-Address-Lease-Time := 463
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)  Thu Dec  6 04:26:32 2018 : Debug :   &DHCP-Vendor = 0x010300a0bc0209555400000000000007030e555400000000000003070307001604
1155545f332e372e332e372e32322e62696e05040a4fff0f0c0200010e010014530100020103110500440044070043004301000201030606c0a8640018070
050005001010201060a000000080101020106ac1000000c0101020106c0a80000100101020106a9fe00001001010201067f00000008330c55543200000000
00000029083b0e55543200000000000307030600003c115554325f332e372e332e362e302e62696e3d040a4fff06
Thu Dec  6 04:26:32 2018 : Debug : (1)  done request
Thu Dec  6 04:26:32 2018 : Debug : (1)  finished request.
Thu Dec  6 04:26:32 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:32 2018 : Debug : Reply will be unicast to CIADDR from original packet.
Thu Dec  6 04:26:32 2018 : Debug : proto_dhcpv4_udp - cleaning up ID 1
Thu Dec  6 04:26:32 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:37 2018 : Info  : Ready to process requests
Thu Dec  6 04:26:37 2018 : Info  : Signalled to terminate
Thu Dec  6 04:26:37 2018 : Info  : Exiting normally
Thu Dec  6 10:40:16 2018 : Info  : FreeRADIUS Version 4.0.0
Thu Dec  6 10:40:16 2018 : Info  : Copyright 1999-2018 The FreeRADIUS server project and contributors
Thu Dec  6 10:40:16 2018 : Info  : There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Thu Dec  6 10:40:16 2018 : Info  : PARTICULAR PURPOSE
Thu Dec  6 10:40:16 2018 : Info  : You may redistribute copies of FreeRADIUS under the terms of the
Thu Dec  6 10:40:16 2018 : Info  : GNU General Public License
Thu Dec  6 10:40:16 2018 : Info  : For more information about these matters, see the file named COPYRIGHT
Thu Dec  6 10:40:16 2018 : Info  : Starting - reading configuration files ...
Thu Dec  6 10:40:16 2018 : Debug : Including dictionary file "/usr/local/share/freeradius/dictionary"
Thu Dec  6 10:40:16 2018 : Debug : Including dictionary file "/usr/local/etc/raddb/dictionary"
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/radiusd.conf
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/clients.conf
Thu Dec  6 10:40:16 2018 : Debug : Including files in directory "/usr/local/etc/raddb/mods-enabled/"
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/always
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/chap
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/client
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail.log
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/digest
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/dhcpv4
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/eap_inner
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/echo
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/escape
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/exec
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expiration
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expr
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/files
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/linelog
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/logintime
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/mschap
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/pam
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/pap
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/passwd
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radius
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radutmp
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/soh
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/stats
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unix
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unpack
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/utf8
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/mac2ip
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis_ippool
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis
Thu Dec  6 10:40:16 2018 : Debug : Including files in directory "/usr/local/etc/raddb/policy.d/"
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/abfab-tr
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/accounting
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/canonicalization
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/control
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/cui
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/debug
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/dhcp
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/eap
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/filter
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/operator-name
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/time
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/policy.d/vendor
Thu Dec  6 10:40:16 2018 : Debug : Including files in directory "/usr/local/etc/raddb/sites-enabled/"
Thu Dec  6 10:40:16 2018 : Debug : including configuration file /usr/local/etc/raddb/sites-enabled/dhcp
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary proto_dhcpv4
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "proto_dhcpv4"
Thu Dec  6 10:40:16 2018 : Debug : Parsing security rules to bootstrap UID / GID / chroot / etc.
Thu Dec  6 10:40:16 2018 : Debug : main {
Thu Dec  6 10:40:16 2018 : Debug :   security {
Thu Dec  6 10:40:16 2018 : Debug :     allow_core_dumps = no
Thu Dec  6 10:40:16 2018 : Debug :     allow_vulnerable_openssl = "no"
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   name = radiusd
Thu Dec  6 10:40:16 2018 : Debug :   name = "radiusd"
Thu Dec  6 10:40:16 2018 : Debug :   prefix = "/usr/local"
Thu Dec  6 10:40:16 2018 : Debug :   local_state_dir = "/usr/local/var"
Thu Dec  6 10:40:16 2018 : Debug :   run_dir = "/usr/local/var/run/radiusd"
Thu Dec  6 10:40:16 2018 : Debug : }
Thu Dec  6 10:40:16 2018 : Debug : Parsing main configuration.
Thu Dec  6 10:40:16 2018 : Debug : main {
Thu Dec  6 10:40:16 2018 : Debug :   server dhcp {
Thu Dec  6 10:40:16 2018 : Debug :     namespace = "dhcpv4"
Thu Dec  6 10:40:16 2018 : Debug :     listen {
Thu Dec  6 10:40:16 2018 : Debug :       type = DHCP-Discover
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "proto_dhcpv4_base"
Thu Dec  6 10:40:16 2018 : Debug :       type = DHCP-Request
Thu Dec  6 10:40:16 2018 : Debug :       type = DHCP-Inform
Thu Dec  6 10:40:16 2018 : Debug :       type = DHCP-Release
Thu Dec  6 10:40:16 2018 : Debug :       type = DHCP-Decline
Thu Dec  6 10:40:16 2018 : Debug :       transport = udp
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary proto_dhcpv4_udp
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "proto_dhcpv4_udp"
Thu Dec  6 10:40:16 2018 : Debug :       udp {
Thu Dec  6 10:40:16 2018 : Debug :         ipaddr = 10.43.18.92
Thu Dec  6 10:40:16 2018 : Debug :         port = 67
Thu Dec  6 10:40:16 2018 : Debug :         broadcast = no
Thu Dec  6 10:40:16 2018 : Debug :         networks {
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :         max_packet_size = 4096
Thu Dec  6 10:40:16 2018 : Debug :         max_attributes = 0
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       limit {
Thu Dec  6 10:40:16 2018 : Debug :         idle_timeout = 30.000000
Thu Dec  6 10:40:16 2018 : Debug :         nak_lifetime = 30.000000
Thu Dec  6 10:40:16 2018 : Debug :         max_connections = 1024
Thu Dec  6 10:40:16 2018 : Debug :         max_clients = 256
Thu Dec  6 10:40:16 2018 : Debug :         max_pending_packets = 256
Thu Dec  6 10:40:16 2018 : Debug :         priority {
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Discover = normal
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Request = normal
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Decline = normal
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Release = normal
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Inform = normal
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Lease-Query = low
Thu Dec  6 10:40:16 2018 : Debug :           DHCP-Bulk-Lease-Query = low
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   security {
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   sbin_dir = "/usr/local/sbin"
Thu Dec  6 10:40:16 2018 : Debug :   logdir = "/usr/local/var/log/radius"
Thu Dec  6 10:40:16 2018 : Debug :   libdir = "/usr/local/lib"
Thu Dec  6 10:40:16 2018 : Debug :   radacctdir = "/usr/local/var/log/radius/radacct"
Thu Dec  6 10:40:16 2018 : Debug :   reverse_lookups = no
Thu Dec  6 10:40:16 2018 : Debug :   reverse_lookups = no
Thu Dec  6 10:40:16 2018 : Debug :   hostname_lookups = yes
Thu Dec  6 10:40:16 2018 : Debug :   hostname_lookups = yes
Thu Dec  6 10:40:16 2018 : Debug :   max_request_time = 30
Thu Dec  6 10:40:16 2018 : Debug :   max_request_time = 30
Thu Dec  6 10:40:16 2018 : Debug :   pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Thu Dec  6 10:40:16 2018 : Debug :   debug_level = 0
Thu Dec  6 10:40:16 2018 : Debug :   log {
Thu Dec  6 10:40:16 2018 : Debug :     colourise = yes
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   resources {
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   thread pool {
Thu Dec  6 10:40:16 2018 : Debug :     num_networks = 1
Thu Dec  6 10:40:16 2018 : Debug :     num_networks = 1
Thu Dec  6 10:40:16 2018 : Debug :     num_workers = 4
Thu Dec  6 10:40:16 2018 : Debug :     num_workers = 4
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug : }
Thu Dec  6 10:40:16 2018 : Info  : Switching to configured log settings
Thu Dec  6 10:40:16 2018 : Debug : radiusd: #### Loading Clients ####
Thu Dec  6 10:40:16 2018 : Debug :   client localhost {
Thu Dec  6 10:40:16 2018 : Debug :     ipaddr = 127.0.0.1
Thu Dec  6 10:40:16 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 10:40:16 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 10:40:16 2018 : Debug :     proto = "*"
Thu Dec  6 10:40:16 2018 : Debug :     limit {
Thu Dec  6 10:40:16 2018 : Debug :       max_connections = 16
Thu Dec  6 10:40:16 2018 : Debug :       lifetime = 0
Thu Dec  6 10:40:16 2018 : Debug :       idle_timeout = 30
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   client localhost_ipv6 {
Thu Dec  6 10:40:16 2018 : Debug :     ipv6addr = ::1
Thu Dec  6 10:40:16 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 10:40:16 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 10:40:16 2018 : Debug :     limit {
Thu Dec  6 10:40:16 2018 : Debug :       max_connections = 16
Thu Dec  6 10:40:16 2018 : Debug :       lifetime = 0
Thu Dec  6 10:40:16 2018 : Debug :       idle_timeout = 30
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :   client private-network-1 {
Thu Dec  6 10:40:16 2018 : Debug :     ipaddr = 10.43.18.0/24
Thu Dec  6 10:40:16 2018 : Debug :     require_message_authenticator = no
Thu Dec  6 10:40:16 2018 : Debug :     secret = <<< secret >>>
Thu Dec  6 10:40:16 2018 : Debug :     limit {
Thu Dec  6 10:40:16 2018 : Debug :       max_connections = 16
Thu Dec  6 10:40:16 2018 : Debug :       lifetime = 0
Thu Dec  6 10:40:16 2018 : Debug :       idle_timeout = 30
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Info  : Debugger not attached
Thu Dec  6 10:40:16 2018 : Debug : #### Bootstrapping listeners ####
Thu Dec  6 10:40:16 2018 : Debug : #### Bootstrapping modules ####
Thu Dec  6 10:40:16 2018 : Debug :  modules {
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_always"
Thu Dec  6 10:40:16 2018 : Debug :     always reject {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "reject"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always fail {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "fail"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always ok {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "ok"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always handled {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "handled"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always invalid {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "invalid"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always userlock {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "userlock"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always notfound {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "notfound"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always noop {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "noop"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     always updated {
Thu Dec  6 10:40:16 2018 : Debug :       rcode = "updated"
Thu Dec  6 10:40:16 2018 : Debug :       simulcount = 0
Thu Dec  6 10:40:16 2018 : Debug :       mpp = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_attr_filter
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_attr_filter"
Thu Dec  6 10:40:16 2018 : Debug :     attr_filter attr_filter.pre-proxy {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy"
Thu Dec  6 10:40:16 2018 : Debug :       relaxed = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     attr_filter attr_filter.post-proxy {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy"
Thu Dec  6 10:40:16 2018 : Debug :       relaxed = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     attr_filter attr_filter.access_reject {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject"
Thu Dec  6 10:40:16 2018 : Debug :       relaxed = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     attr_filter attr_filter.access_challenge {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge"
Thu Dec  6 10:40:16 2018 : Debug :       relaxed = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     attr_filter attr_filter.accounting_response {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response"
Thu Dec  6 10:40:16 2018 : Debug :       relaxed = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_cache
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_cache"
Thu Dec  6 10:40:16 2018 : Debug :     cache cache_eap {
Thu Dec  6 10:40:16 2018 : Debug :       driver = "rlm_cache_rbtree"
Thu Dec  6 10:40:16 2018 : Debug :       ttl = 15
Thu Dec  6 10:40:16 2018 : Debug :       max_entries = 0
Thu Dec  6 10:40:16 2018 : Debug :       epoch = 0
Thu Dec  6 10:40:16 2018 : Debug :       add_stats = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_chap
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_chap"
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_client"
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_detail
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_detail"
Thu Dec  6 10:40:16 2018 : Debug :     detail {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/detail-%Y-%m-%d"
Thu Dec  6 10:40:16 2018 : Debug :       header = "%t"
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       locking = no
Thu Dec  6 10:40:16 2018 : Debug :       escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       log_packet_header = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     detail auth_log {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/auth-detail-%Y-%m-%d"
Thu Dec  6 10:40:16 2018 : Debug :       header = "%t"
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       locking = no
Thu Dec  6 10:40:16 2018 : Debug :       escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       log_packet_header = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     detail reply_log {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/reply-detail-%Y-%m-%d"
Thu Dec  6 10:40:16 2018 : Debug :       header = "%t"
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       locking = no
Thu Dec  6 10:40:16 2018 : Debug :       escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       log_packet_header = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     detail pre_proxy_log {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/pre-proxy-detail-%Y-%m-%d"
Thu Dec  6 10:40:16 2018 : Debug :       header = "%t"
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       locking = no
Thu Dec  6 10:40:16 2018 : Debug :       escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       log_packet_header = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     detail post_proxy_log {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-S
rc-IPv6-Address}}/post-proxy-detail-%Y-%m-%d"
Thu Dec  6 10:40:16 2018 : Debug :       header = "%t"
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       locking = no
Thu Dec  6 10:40:16 2018 : Debug :       escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       log_packet_header = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_digest
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_digest"
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_dhcpv4"
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_eap
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_eap"
Thu Dec  6 10:40:16 2018 : Debug :     eap inner-eap {
Thu Dec  6 10:40:16 2018 : Debug :       default_eap_type = mschapv2
Thu Dec  6 10:40:16 2018 : Debug :       type = md5
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_eap_md5
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_eap_md5"
Thu Dec  6 10:40:16 2018 : Debug :       type = gtc
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_eap_gtc
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_eap_gtc"
Thu Dec  6 10:40:16 2018 : Debug :       gtc {
Thu Dec  6 10:40:16 2018 : Debug :         challenge = "Password: "
Thu Dec  6 10:40:16 2018 : Debug :         auth_type = PAP
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       type = mschapv2
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_eap_mschapv2
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_eap_mschapv2"
Thu Dec  6 10:40:16 2018 : Debug :       mschapv2 {
Thu Dec  6 10:40:16 2018 : Debug :         with_ntdomain_hack = no
Thu Dec  6 10:40:16 2018 : Debug :         auth_type = mschap
Thu Dec  6 10:40:16 2018 : Debug :         send_error = no
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       type = tls
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_eap_tls
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_eap_tls"
Thu Dec  6 10:40:16 2018 : Debug :       tls {
Thu Dec  6 10:40:16 2018 : Debug :         tls = "tls-peer"
Thu Dec  6 10:40:16 2018 : Debug :         require_client_cert = yes
Thu Dec  6 10:40:16 2018 : Debug :         include_length = yes
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       ignore_unknown_eap_types = no
Thu Dec  6 10:40:16 2018 : Debug :       cisco_accounting_username_bug = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_exec"
Thu Dec  6 10:40:16 2018 : Debug :     exec echo {
Thu Dec  6 10:40:16 2018 : Debug :       wait = yes
Thu Dec  6 10:40:16 2018 : Debug :       program = "/bin/echo %{User-Name}"
Thu Dec  6 10:40:16 2018 : Debug :       input_pairs = "request"
Thu Dec  6 10:40:16 2018 : Debug :       output_pairs = "reply"
Thu Dec  6 10:40:16 2018 : Debug :       shell_escape = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_escape"
Thu Dec  6 10:40:16 2018 : Debug :     escape {
Thu Dec  6 10:40:16 2018 : Debug :       safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     exec {
Thu Dec  6 10:40:16 2018 : Debug :       wait = no
Thu Dec  6 10:40:16 2018 : Debug :       input_pairs = "request"
Thu Dec  6 10:40:16 2018 : Debug :       shell_escape = yes
Thu Dec  6 10:40:16 2018 : Debug :       timeout = 10
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_expiration
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_expiration"
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_expr"
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_files
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_files"
Thu Dec  6 10:40:16 2018 : Debug :     files {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/files/authorize"
Thu Dec  6 10:40:16 2018 : Debug :       acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting"
Thu Dec  6 10:40:16 2018 : Debug :       preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy"
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_linelog"
Thu Dec  6 10:40:16 2018 : Debug :     linelog {
Thu Dec  6 10:40:16 2018 : Debug :       destination = "file"
Thu Dec  6 10:40:16 2018 : Debug :       delimiter = " "
Thu Dec  6 10:40:16 2018 : Debug :       file {
Thu Dec  6 10:40:16 2018 : Debug :         filename = "/usr/local/var/log/radius/linelog"
Thu Dec  6 10:40:16 2018 : Debug :         permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :         escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       syslog {
Thu Dec  6 10:40:16 2018 : Debug :         severity = "info"
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       unix {
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       tcp {
Thu Dec  6 10:40:16 2018 : Debug :         port = 514
Thu Dec  6 10:40:16 2018 : Debug :         timeout = 2.000000
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       udp {
Thu Dec  6 10:40:16 2018 : Debug :         port = 514
Thu Dec  6 10:40:16 2018 : Debug :         timeout = 2.000000
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     linelog log_accounting {
Thu Dec  6 10:40:16 2018 : Debug :       destination = "file"
Thu Dec  6 10:40:16 2018 : Debug :       delimiter = " "
Thu Dec  6 10:40:16 2018 : Debug :       file {
Thu Dec  6 10:40:16 2018 : Debug :         filename = "/usr/local/var/log/radius/linelog-accounting"
Thu Dec  6 10:40:16 2018 : Debug :         permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :         escape_filenames = no
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       syslog {
Thu Dec  6 10:40:16 2018 : Debug :         severity = "info"
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       unix {
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       tcp {
Thu Dec  6 10:40:16 2018 : Debug :         timeout = 1000.000000
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       udp {
Thu Dec  6 10:40:16 2018 : Debug :         timeout = 1000.000000
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_logintime
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_logintime"
Thu Dec  6 10:40:16 2018 : Debug :     logintime {
Thu Dec  6 10:40:16 2018 : Debug :       minimum_timeout = 60
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_mschap"
Thu Dec  6 10:40:16 2018 : Debug :     mschap {
Thu Dec  6 10:40:16 2018 : Debug :       use_mppe = yes
Thu Dec  6 10:40:16 2018 : Debug :       require_encryption = no
Thu Dec  6 10:40:16 2018 : Debug :       require_strong = no
Thu Dec  6 10:40:16 2018 : Debug :       with_ntdomain_hack = yes
Thu Dec  6 10:40:16 2018 : Debug :       passchange {
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       allow_retry = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     exec ntlm_auth {
Thu Dec  6 10:40:16 2018 : Debug :       wait = yes
Thu Dec  6 10:40:16 2018 : Debug :       program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap
:User-Name} --password=%{User-Password}"
Thu Dec  6 10:40:16 2018 : Debug :       shell_escape = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_pam
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_pam"
Thu Dec  6 10:40:16 2018 : Debug :     pam {
Thu Dec  6 10:40:16 2018 : Debug :       pam_auth = "radiusd"
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_pap
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_pap"
Thu Dec  6 10:40:16 2018 : Debug :     pap {
Thu Dec  6 10:40:16 2018 : Debug :       normalise = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_passwd
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_passwd"
Thu Dec  6 10:40:16 2018 : Debug :     passwd etc_passwd {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/etc/passwd"
Thu Dec  6 10:40:16 2018 : Debug :       format = "*User-Name:Crypt-Password:"
Thu Dec  6 10:40:16 2018 : Debug :       delimiter = ":"
Thu Dec  6 10:40:16 2018 : Debug :       ignore_nislike = no
Thu Dec  6 10:40:16 2018 : Debug :       ignore_empty = yes
Thu Dec  6 10:40:16 2018 : Debug :       allow_multiple_keys = no
Thu Dec  6 10:40:16 2018 : Debug :       hash_size = 100
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_radius
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_radius"
Thu Dec  6 10:40:16 2018 : Debug :     radius {
Thu Dec  6 10:40:16 2018 : Debug :       transport = udp
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_radius_udp
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_radius_udp"
Thu Dec  6 10:40:16 2018 : Debug :       udp {
Thu Dec  6 10:40:16 2018 : Debug :         ipaddr = 127.0.0.1
Thu Dec  6 10:40:16 2018 : Debug :         port = 1812
Thu Dec  6 10:40:16 2018 : Debug :         secret = "testing123"
Thu Dec  6 10:40:16 2018 : Debug :         max_packet_size = 4096
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       type = Access-Request
Thu Dec  6 10:40:16 2018 : Debug :       type = Accounting-Request
Thu Dec  6 10:40:16 2018 : Debug :       status_checks {
Thu Dec  6 10:40:16 2018 : Debug :         type = Status-Server
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       max_connections = 32
Thu Dec  6 10:40:16 2018 : Debug :       max_attributes = 255
Thu Dec  6 10:40:16 2018 : Debug :       connection {
Thu Dec  6 10:40:16 2018 : Debug :         connect_timeout = 5.000000
Thu Dec  6 10:40:16 2018 : Debug :         reconnect_delay = 5.000000
Thu Dec  6 10:40:16 2018 : Debug :         idle_timeout = 5.000000
Thu Dec  6 10:40:16 2018 : Debug :         zombie_period = 10.000000
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       Access-Request {
Thu Dec  6 10:40:16 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_count = 2
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       Accounting-Request {
Thu Dec  6 10:40:16 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_count = 5
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :       Status-Server {
Thu Dec  6 10:40:16 2018 : Debug :         initial_retransmission_time = 2
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_time = 16
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_count = 5
Thu Dec  6 10:40:16 2018 : Debug :         maximum_retransmission_duration = 30
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_radutmp
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_radutmp"
Thu Dec  6 10:40:16 2018 : Debug :     radutmp {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/radutmp"
Thu Dec  6 10:40:16 2018 : Debug :       username = "%{User-Name}"
Thu Dec  6 10:40:16 2018 : Debug :       case_sensitive = yes
Thu Dec  6 10:40:16 2018 : Debug :       check_with_nas = yes
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 384
Thu Dec  6 10:40:16 2018 : Debug :       caller_id = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_soh
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_soh"
Thu Dec  6 10:40:16 2018 : Debug :     soh {
Thu Dec  6 10:40:16 2018 : Debug :       dhcp = yes
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :     radutmp sradutmp {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/var/log/radius/sradutmp"
Thu Dec  6 10:40:16 2018 : Debug :       username = "%{User-Name}"
Thu Dec  6 10:40:16 2018 : Debug :       case_sensitive = yes
Thu Dec  6 10:40:16 2018 : Debug :       check_with_nas = yes
Thu Dec  6 10:40:16 2018 : Debug :       permissions = 420
Thu Dec  6 10:40:16 2018 : Debug :       caller_id = no
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_stats
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_stats"
Thu Dec  6 10:40:16 2018 : Debug :     stats {
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_unix
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_unix"
Thu Dec  6 10:40:16 2018 : Debug :     unix {
Thu Dec  6 10:40:16 2018 : Debug :       radwtmp = "/usr/local/var/log/radius/radwtmp"
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug : Creating attribute Unix-Group
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_unpack
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_unpack"
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_utf8"
Thu Dec  6 10:40:16 2018 : Debug :     passwd mac2ip {
Thu Dec  6 10:40:16 2018 : Debug :       filename = "/usr/local/etc/raddb/mods-config/passwd/mac2ip"
Thu Dec  6 10:40:16 2018 : Debug :       format = "*DHCP-Client-Hardware-Address:=DHCP-Your-IP-Address"
Thu Dec  6 10:40:16 2018 : Debug :       delimiter = ","
Thu Dec  6 10:40:16 2018 : Debug :       ignore_nislike = yes
Thu Dec  6 10:40:16 2018 : Debug :       ignore_empty = yes
Thu Dec  6 10:40:16 2018 : Debug :       allow_multiple_keys = no
Thu Dec  6 10:40:16 2018 : Debug :       hash_size = 100
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : libfreeradius-redis: libhiredis version: 0.12.1
Thu Dec  6 10:40:16 2018 : Debug : Loading dictionary rlm_redis_ippool
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_redis_ippool"
Thu Dec  6 10:40:16 2018 : Debug :     redis_ippool {
Thu Dec  6 10:40:16 2018 : Debug :       copy_on_update = yes
Thu Dec  6 10:40:16 2018 : Debug :       redis {
Thu Dec  6 10:40:16 2018 : Debug :         server = "10.43.16.224"
Thu Dec  6 10:40:16 2018 : Debug :         port = 6379
Thu Dec  6 10:40:16 2018 : Debug :         database = 0
Thu Dec  6 10:40:16 2018 : Debug :         max_nodes = 20
Thu Dec  6 10:40:16 2018 : Debug :         max_alt = 3
Thu Dec  6 10:40:16 2018 : Debug :         max_redirects = 2
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Info  : libfreeradius-redis: libhiredis version: 0.12.1
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_redis"
Thu Dec  6 10:40:16 2018 : Debug :     redis {
Thu Dec  6 10:40:16 2018 : Debug :       server = "10.43.16.224"
Thu Dec  6 10:40:16 2018 : Debug :       port = 6379
Thu Dec  6 10:40:16 2018 : Debug :       database = 0
Thu Dec  6 10:40:16 2018 : Debug :       max_nodes = 20
Thu Dec  6 10:40:16 2018 : Debug :       max_alt = 3
Thu Dec  6 10:40:16 2018 : Debug :       max_redirects = 2
Thu Dec  6 10:40:16 2018 : Debug :     }
Thu Dec  6 10:40:16 2018 : Debug :   instantiate {
Thu Dec  6 10:40:16 2018 : Debug :   }
Thu Dec  6 10:40:16 2018 : Debug :  } # modules
Thu Dec  6 10:40:16 2018 : Debug : #### Instantiating listeners ####
Thu Dec  6 10:40:16 2018 : Debug : Compiling policies in server dhcp { ... }
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Discover {...}
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Request {...}
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Decline {...}
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Inform {...}
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Release {...}
Thu Dec  6 10:40:16 2018 : Debug : compiling - recv DHCP-Lease-Query {...}
Thu Dec  6 10:40:16 2018 : Debug : #### Instantiating modules ####
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "attr_filter.access_challenge"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "attr_filter.access_reject"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_reject
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "attr_filter.accounting_response"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "attr_filter.post-proxy"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "attr_filter.pre-proxy"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "auth_log"
Thu Dec  6 10:40:16 2018 : Debug : rlm_detail (auth_log) - 'User-Password' suppressed, will not appear in detail output
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "cache_eap"
Thu Dec  6 10:40:16 2018 : Info  : Loaded module "rlm_cache_rbtree"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "detail"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "etc_passwd"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "expiration"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "fail"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "files"
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/authorize
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/accounting
Thu Dec  6 10:40:16 2018 : Debug : Reading file /usr/local/etc/raddb/mods-config/files/pre-proxy
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "handled"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "inner-eap"
Thu Dec  6 10:40:16 2018 : Debug :       tls-config tls-peer {
Thu Dec  6 10:40:16 2018 : Debug :         auto_chain = yes
Thu Dec  6 10:40:16 2018 : Debug :         chain {
Thu Dec  6 10:40:16 2018 : Debug :           format = pem
Thu Dec  6 10:40:16 2018 : Debug :           certificate_file = "/usr/local/etc/raddb/certs/rsa/server.pem"
Thu Dec  6 10:40:16 2018 : Debug :           private_key_password = <<< secret >>>
Thu Dec  6 10:40:16 2018 : Debug :           private_key_file = "/usr/local/etc/raddb/certs/rsa/server.key"
Thu Dec  6 10:40:16 2018 : Debug :           ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
Thu Dec  6 10:40:16 2018 : Debug :           verify_mode = hard
Thu Dec  6 10:40:16 2018 : Debug :           include_root_ca = no
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :         verify_depth = 0
Thu Dec  6 10:40:16 2018 : Debug :         ca_path = "/usr/local/etc/raddb/certs"
Thu Dec  6 10:40:16 2018 : Debug :         ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
Thu Dec  6 10:40:16 2018 : Debug :         dh_file = "/usr/local/etc/raddb/certs/dh"
Thu Dec  6 10:40:16 2018 : Debug :         fragment_size = 16384
Thu Dec  6 10:40:16 2018 : Debug :         check_crl = no
Thu Dec  6 10:40:16 2018 : Debug :         cipher_server_preference = yes
Thu Dec  6 10:40:16 2018 : Debug :         allow_renegotiation = no
Thu Dec  6 10:40:16 2018 : Debug :         ecdh_curve = "prime256v1"
Thu Dec  6 10:40:16 2018 : Debug :         tls_min_version = 1.000000
Thu Dec  6 10:40:16 2018 : Debug :         cache {
Thu Dec  6 10:40:16 2018 : Debug :           lifetime = 86400
Thu Dec  6 10:40:16 2018 : Debug :           verify = no
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :         verify {
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :         ocsp {
Thu Dec  6 10:40:16 2018 : Debug :           enable = no
Thu Dec  6 10:40:16 2018 : Debug :           override_cert_url = no
Thu Dec  6 10:40:16 2018 : Debug :           use_nonce = yes
Thu Dec  6 10:40:16 2018 : Debug :           timeout = 0
Thu Dec  6 10:40:16 2018 : Debug :           softfail = no
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :         staple {
Thu Dec  6 10:40:16 2018 : Debug :           enable = no
Thu Dec  6 10:40:16 2018 : Debug :           override_cert_url = no
Thu Dec  6 10:40:16 2018 : Debug :           use_nonce = yes
Thu Dec  6 10:40:16 2018 : Debug :           timeout = 0
Thu Dec  6 10:40:16 2018 : Debug :           softfail = no
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "invalid"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "linelog"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "log_accounting"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "logintime"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "mac2ip"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "mschap"
Thu Dec  6 10:40:16 2018 : Debug : mschap: using internal authentication
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "noop"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "notfound"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "ok"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "pam"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "post_proxy_log"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "pre_proxy_log"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "radius"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "redis"
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Initialising connection pool
Thu Dec  6 10:40:16 2018 : Debug :       pool {
Thu Dec  6 10:40:16 2018 : Debug :         start = 4
Thu Dec  6 10:40:16 2018 : Debug :         min = 1
Thu Dec  6 10:40:16 2018 : Debug :         max = 4
Thu Dec  6 10:40:16 2018 : Debug :         max_pending = 0
Thu Dec  6 10:40:16 2018 : Debug :         spare = 1
Thu Dec  6 10:40:16 2018 : Debug :         uses = 0
Thu Dec  6 10:40:16 2018 : Debug :         lifetime = 86400
Thu Dec  6 10:40:16 2018 : Debug :         cleanup_interval = 300
Thu Dec  6 10:40:16 2018 : Debug :         idle_timeout = 600
Thu Dec  6 10:40:16 2018 : Debug :         connect_timeout = 3.000000
Thu Dec  6 10:40:16 2018 : Debug :         held_trigger_min = 0.000000
Thu Dec  6 10:40:16 2018 : Debug :         held_trigger_max = 0.500000
Thu Dec  6 10:40:16 2018 : Debug :         retry_delay = 30
Thu Dec  6 10:40:16 2018 : Debug :         spread = no
Thu Dec  6 10:40:16 2018 : Debug :       }
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (2), 1 of 2 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (3), 1 of 1 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Reserved connection (3)
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis): Bootstrap server "10.43.16.224" returned: ERR This instance has cluster
support disabled
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Released connection (3)
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "redis_ippool"
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Initialising connection pool
Thu Dec  6 10:40:16 2018 : Debug :         pool {
Thu Dec  6 10:40:16 2018 : Debug :           start = 0
Thu Dec  6 10:40:16 2018 : Debug :           min = 4
Thu Dec  6 10:40:16 2018 : Debug :           max = 4
Thu Dec  6 10:40:16 2018 : Debug :           max_pending = 0
Thu Dec  6 10:40:16 2018 : Debug :           spare = 1
Thu Dec  6 10:40:16 2018 : Debug :           uses = 0
Thu Dec  6 10:40:16 2018 : Debug :           lifetime = 0
Thu Dec  6 10:40:16 2018 : Debug :           cleanup_interval = 30
Thu Dec  6 10:40:16 2018 : Debug :           idle_timeout = 60
Thu Dec  6 10:40:16 2018 : Debug :           connect_timeout = 3.000000
Thu Dec  6 10:40:16 2018 : Debug :           held_trigger_min = 0.000000
Thu Dec  6 10:40:16 2018 : Debug :           held_trigger_max = 0.500000
Thu Dec  6 10:40:16 2018 : Debug :           retry_delay = 30
Thu Dec  6 10:40:16 2018 : Debug :           spread = no
Thu Dec  6 10:40:16 2018 : Debug :         }
Thu Dec  6 10:40:16 2018 : Warn  : rlm_redis (redis) [1] - Ignoring "spare = 1", forcing to "spare = 0"
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - 0 of 0 connections in use.  You  may need to increase "spare"
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Reserved connection (0)
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Released connection (0)
Thu Dec  6 10:40:16 2018 : Info  : rlm_redis (redis) [1] - Need 3 more connections to reach min connections (4)
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
Thu Dec  6 10:40:16 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "reject"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "reply_log"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "stats"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "updated"
Thu Dec  6 10:40:16 2018 : Debug : Instantiating module "userlock"
Thu Dec  6 10:40:16 2018 : Debug : [1] radius - Connection initialising
Thu Dec  6 10:40:16 2018 : Debug : [1] radius - Connection initialised
Thu Dec  6 10:40:16 2018 : Debug : Scheduler created in single-threaded mode
Thu Dec  6 10:40:16 2018 : Debug : #### Opening listener interfaces ####
Thu Dec  6 10:40:16 2018 : Debug : Listening on dhcpv4 address proto_dhcpv4_udp server 10.43.18.92 port 67 bound to virtual s
erver dhcp
Thu Dec  6 10:40:16 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 10:40:16 2018 : Debug : radius - Connection open - proto udp local 0.0.0.0 port 44239 remote 127.0.0.1 port 1812
Thu Dec  6 10:40:16 2018 : Debug : radius - Allocated Status-Server ID 0 for status checks on connection proto udp local 0.0.
0.0 port 44239 remote 127.0.0.1 port 1812
Thu Dec  6 10:40:16 2018 : Debug : radius - Setting idle timeout to +5.000000 for connection proto udp local 0.0.0.0 port 442
39 remote 127.0.0.1 port 1812
Thu Dec  6 10:40:16 2018 : Debug : [1] radius - Connection established
Thu Dec  6 10:40:16 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 10:40:16 2018 : Debug : Waking up in 4.9 seconds.
Thu Dec  6 10:40:19 2018 : Debug : proto_dhcpv4_udp - Received DHCP-Discover XID 00000000 length 304 proto_dhcpv4_udp server
10.43.18.92 port 67
Thu Dec  6 10:40:19 2018 : Debug : Network received packet size 304
Thu Dec  6 10:40:19 2018 : Debug : Resetting worker 30 cleanup timer to +0s
Thu Dec  6 10:40:19 2018 : Debug : (0)  running request
(0)  Thu Dec  6 10:40:19 2018 : Debug : Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Opcode = Client-Message
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hardware-Type = Ethernet
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hardware-Address-Length = 6
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hop-Count = 1
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Transaction-Id = 0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Number-of-Seconds = 0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Flags = 0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Client-IP-Address = 127.0.0.1
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Your-IP-Address = 0.0.0.0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Server-IP-Address = 0.0.0.0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Gateway-IP-Address = 127.0.0.1
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:01
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Message-Type = DHCP-Discover
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Subnet-Mask
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Broadcast-Address
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Time-Offset
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Router-Address
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name-Server
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Hostname
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Subscriber-Id = "00a0bc000001 at aut.res.viasat.com"
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Relay-Remote-Id = 0x00a0bc000001
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Relay-Circuit-Id = 0x000000222066
(0)  Thu Dec  6 10:40:19 2018 : Debug : Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp
(0)  Thu Dec  6 10:40:19 2018 : Debug : recv DHCP-Discover {
(0)  Thu Dec  6 10:40:19 2018 : Debug :   update reply {
(0)  Thu Dec  6 10:40:19 2018 : Debug :     DHCP-Message-Type = DHCP-Offer
(0)  Thu Dec  6 10:40:19 2018 : Debug :   } # update reply (noop)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   update reply {
(0)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-Subnet-Mask = 255.255.255.0
(0)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-Router-Address = 10.43.18.92
(0)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-IP-Address-Lease-Time = 900
(0)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-DHCP-Server-Identifier = 10.43.18.92
(0)  Thu Dec  6 10:40:19 2018 : Debug :   } # update reply (noop)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   update control {
(0)  Thu Dec  6 10:40:19 2018 : Debug :     &Pool-Name := "local"
(0)  Thu Dec  6 10:40:19 2018 : Debug :   } # update control (noop)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - Allocating lease from pool "local", to "00:a0:bc:00:00:01", expires
in 900s
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - Reserved connection (1)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - [1] >>> Sending command(s) to 10.43.16.224:6379
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - [1] <<< Returned: success
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - Released connection (1)
(0)  Thu Dec  6 10:40:19 2018 : Info  :   redis_ippool - Need 2 more connections to reach min connections (4)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - Opening additional connection (2), 1 of 2 pending slots used
Thu Dec  6 10:40:19 2018 : Debug : rlm_redis (redis) [1]: Connecting node to 10.43.16.224:6379
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.24.111
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 802
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - IP address lease allocated
(0)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool (updated)
(0)  Thu Dec  6 10:40:19 2018 : Debug :   ok (ok)
(0)  Thu Dec  6 10:40:19 2018 : Debug : } # recv DHCP-Discover (updated)
(0)  Thu Dec  6 10:40:19 2018 : Debug : Sent DHCP-Offer XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Message-Type = DHCP-Offer
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Subnet-Mask = 255.255.255.0
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Router-Address = 10.43.18.92
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-IP-Address-Lease-Time := 802
(0)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
Thu Dec  6 10:40:19 2018 : Debug : (0)  done request
Thu Dec  6 10:40:19 2018 : Debug : (0)  finished request.
Thu Dec  6 10:40:19 2018 : Debug : Waking up in 1.9 seconds.
Thu Dec  6 10:40:19 2018 : Debug : Reply will be unicast to CIADDR from original packet.
Thu Dec  6 10:40:19 2018 : Debug : proto_dhcpv4_udp - cleaning up ID 1
Thu Dec  6 10:40:19 2018 : Debug : Waking up in 1.9 seconds.
Thu Dec  6 10:40:19 2018 : Debug : proto_dhcpv4_udp - Received DHCP-Request XID 00000000 length 325 proto_dhcpv4_udp server 1
0.43.18.92 port 67
Thu Dec  6 10:40:19 2018 : Debug : Network received packet size 325
Thu Dec  6 10:40:19 2018 : Debug : Resetting worker 30 cleanup timer to +0s
Thu Dec  6 10:40:19 2018 : Debug : (1)  running request
(1)  Thu Dec  6 10:40:19 2018 : Debug : Received DHCP-Request XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Opcode = Client-Message
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hardware-Type = Ethernet
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hardware-Address-Length = 6
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Hop-Count = 1
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Transaction-Id = 0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Number-of-Seconds = 0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Flags = 0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Client-IP-Address = 127.0.0.1
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Your-IP-Address = 0.0.0.0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Server-IP-Address = 0.0.0.0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Gateway-IP-Address = 127.0.0.1
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:01
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Requested-IP-Address = 192.168.24.111
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Message-Type = DHCP-Request
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Subnet-Mask
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Broadcast-Address
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Time-Offset
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Router-Address
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Domain-Name-Server
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Parameter-Request-List = DHCP-Hostname
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Client-Identifier = 0x01afac00000000
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Subscriber-Id = "00a0bc000001 at aut.res.viasat.com"
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Relay-Remote-Id = 0x00a0bc000001
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Relay-Circuit-Id = 0x000000222066
(1)  Thu Dec  6 10:40:19 2018 : Debug : Running 'recv DHCP-Request' from file /usr/local/etc/raddb/sites-enabled/dhcp
(1)  Thu Dec  6 10:40:19 2018 : Debug : recv DHCP-Request {
(1)  Thu Dec  6 10:40:19 2018 : Debug :   update reply {
(1)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-Message-Type = DHCP-Ack
(1)  Thu Dec  6 10:40:19 2018 : Debug :   } # update reply (noop)
(1)  Thu Dec  6 10:40:19 2018 : Debug :   update reply {
(1)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-Subnet-Mask = 255.255.255.0
(1)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-Router-Address = 10.43.18.92
(1)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-IP-Address-Lease-Time = 900
(1)  Thu Dec  6 10:40:19 2018 : Debug :     &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)  Thu Dec  6 10:40:19 2018 : Debug :   } # update reply (noop)
(1)  Thu Dec  6 10:40:19 2018 : Debug :   if ("%{redis: EXISTS {local\}:pool}" == 1) {
(1)  Thu Dec  6 10:40:19 2018 : Debug :     EXPAND %{redis: EXISTS {local\}:pool}
(1)  Thu Dec  6 10:40:19 2018 : Debug :     Reserved connection (3)
(1)  Thu Dec  6 10:40:19 2018 : Debug :     [1] >>> Sending command(s) to 10.43.16.224:6379
(1)  Thu Dec  6 10:40:19 2018 : Debug :     Executing command: EXISTS
(1)  Thu Dec  6 10:40:19 2018 : Debug :     With arguments
(1)  Thu Dec  6 10:40:19 2018 : Debug :       [1] {local\}:pool
(1)  Thu Dec  6 10:40:19 2018 : Debug :     [1] <<< Returned: success
(1)  Thu Dec  6 10:40:19 2018 : Debug :     Released connection (3)
(1)  Thu Dec  6 10:40:19 2018 : Debug :        --> 0
(1)  Thu Dec  6 10:40:19 2018 : Debug :     ...
(1)  Thu Dec  6 10:40:19 2018 : Debug :   }
(1)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool - Pool attribute not present in request.  Doing nothing
(1)  Thu Dec  6 10:40:19 2018 : Debug :   redis_ippool (noop)
(1)  Thu Dec  6 10:40:19 2018 : Debug :   if (updated) {
(1)  Thu Dec  6 10:40:19 2018 : Debug :     ...
(1)  Thu Dec  6 10:40:19 2018 : Debug :   }
(1)  Thu Dec  6 10:40:19 2018 : Debug :   ok (ok)
(1)  Thu Dec  6 10:40:19 2018 : Debug : } # recv DHCP-Request (ok)
(1)  Thu Dec  6 10:40:19 2018 : ERROR : DHCP-Ack packet does not have YIADDR.  The client will not receive an IP address.
(1)  Thu Dec  6 10:40:19 2018 : Debug : Sent DHCP-Ack XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Message-Type = DHCP-Ack
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Subnet-Mask = 255.255.255.0
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-Router-Address = 10.43.18.92
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-IP-Address-Lease-Time = 900
(1)  Thu Dec  6 10:40:19 2018 : Debug :   &DHCP-DHCP-Server-Identifier = 10.43.18.92
Thu Dec  6 10:40:19 2018 : Debug : (1)  done request
Thu Dec  6 10:40:19 2018 : Debug : (1)  finished request.
Thu Dec  6 10:40:19 2018 : Debug : Waking up in 1.9 seconds.
Thu Dec  6 10:40:19 2018 : Debug : Reply will be unicast to CIADDR from original packet.
Thu Dec  6 10:40:19 2018 : Debug : proto_dhcpv4_udp - cleaning up ID 1
Thu Dec  6 10:40:19 2018 : Debug : Waking up in 1.9 seconds.
Thu Dec  6 10:40:21 2018 : Debug : radius - Idle timeout for connection proto udp local 0.0.0.0 port 44239 remote 127.0.0.1 p
ort 1812
Thu Dec  6 10:40:21 2018 : Debug : [1] radius - Closing connection (18)
Thu Dec  6 10:40:21 2018 : Debug : radius - Connection closed - proto udp local 0.0.0.0 port 44239 remote 127.0.0.1 port 1812
Thu Dec  6 10:40:21 2018 : Info  : Ready to process requests
Thu Dec  6 10:40:22 2018 : Info  : Ready to process requests
Thu Dec  6 10:40:22 2018 : Info  : Signalled to terminate
Thu Dec  6 10:40:22 2018 : Info  : Exiting normally


Regards,
Nagamani Chinnapaiyan



More information about the Freeradius-Users mailing list