[root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# [root@kdc ~]# gdb --args radiusd -Xxx GNU gdb (GDB) Fedora 7.8.2-39.fc21 Copyright (C) 2014 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: . Find the GDB manual and other documentation resources online at: . For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from radiusd...done. (gdb) run Starting program: /usr/local/sbin/radiusd -Xxx Missing separate debuginfos, use: debuginfo-install glibc-2.20-8.fc21.x86_64 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". Sun Feb 4 18:40:52 2018 : Debug: Server was built with: Sun Feb 4 18:40:52 2018 : Debug: accounting : yes Sun Feb 4 18:40:52 2018 : Debug: authentication : yes Sun Feb 4 18:40:52 2018 : Debug: ascend-binary-attributes : yes Sun Feb 4 18:40:52 2018 : Debug: coa : yes Sun Feb 4 18:40:52 2018 : Debug: control-socket : yes Sun Feb 4 18:40:52 2018 : Debug: detail : yes Sun Feb 4 18:40:52 2018 : Debug: dhcp : yes Sun Feb 4 18:40:52 2018 : Debug: dynamic-clients : yes Sun Feb 4 18:40:52 2018 : Debug: osfc2 : no Sun Feb 4 18:40:52 2018 : Debug: proxy : yes Sun Feb 4 18:40:52 2018 : Debug: regex-pcre : yes Sun Feb 4 18:40:52 2018 : Debug: regex-posix : no Sun Feb 4 18:40:52 2018 : Debug: regex-posix-extended : no Sun Feb 4 18:40:52 2018 : Debug: session-management : yes Sun Feb 4 18:40:52 2018 : Debug: stats : yes Sun Feb 4 18:40:52 2018 : Debug: tcp : yes Sun Feb 4 18:40:52 2018 : Debug: threads : yes Sun Feb 4 18:40:52 2018 : Debug: tls : yes Sun Feb 4 18:40:52 2018 : Debug: unlang : yes Sun Feb 4 18:40:52 2018 : Debug: vmps : yes Sun Feb 4 18:40:52 2018 : Debug: developer : yes Sun Feb 4 18:40:52 2018 : Debug: Server core libs: Sun Feb 4 18:40:52 2018 : Debug: freeradius-server : 3.0.17 Sun Feb 4 18:40:52 2018 : Debug: talloc : 2.0.* Sun Feb 4 18:40:52 2018 : Debug: ssl : 1.1.1 dev Sun Feb 4 18:40:52 2018 : Debug: pcre : 8.35 2014-04-04 Sun Feb 4 18:40:52 2018 : Debug: Endianness: Sun Feb 4 18:40:52 2018 : Debug: little Sun Feb 4 18:40:52 2018 : Debug: Compilation flags: Sun Feb 4 18:40:52 2018 : Debug: cppflags : -isystem /usr/local/include/ Sun Feb 4 18:40:52 2018 : Debug: cflags : -I. -Isrc -include src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h -include src/freeradius-devel/features.h -include src/freeradius-devel/radpaths.h -fno-strict-aliasing -Wno-date-time -g3 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -Wshadow -Wpointer-arith -Wcast-qual -Wcast-align -Wwrite-strings -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -Wnested-externs -W -Wredundant-decls -Wundef -Wformat-y2k -Wno-format-extra-args -Wno-format-zero-length -Wno-cast-align -Wformat-nonliteral -Wformat-security -Wformat=2 -DWITH_VERIFY_PTR=1 -DIS_MODULE=1 Sun Feb 4 18:40:52 2018 : Debug: ldflags : -L/usr/local/lib64 -Wl,-rpath,/usr/local/lib64 Sun Feb 4 18:40:52 2018 : Debug: libs : -lcrypto -lssl -ltalloc -lpcre -lnsl -lresolv -ldl -lpthread -lreadline Sun Feb 4 18:40:52 2018 : Debug: Sun Feb 4 18:40:52 2018 : Info: FreeRADIUS Version 3.0.17 Sun Feb 4 18:40:52 2018 : Info: Copyright (C) 1999-2017 The FreeRADIUS server project and contributors Sun Feb 4 18:40:52 2018 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Sun Feb 4 18:40:52 2018 : Info: PARTICULAR PURPOSE Sun Feb 4 18:40:52 2018 : Info: You may redistribute copies of FreeRADIUS under the terms of the Sun Feb 4 18:40:52 2018 : Info: GNU General Public License Sun Feb 4 18:40:52 2018 : Info: For more information about these matters, see the file named COPYRIGHT Detaching after fork from child process 26157. Sun Feb 4 18:40:52 2018 : Info: Starting - reading configuration files ... Sun Feb 4 18:40:52 2018 : Debug: including dictionary file /usr/local/share/freeradius/dictionary Sun Feb 4 18:40:52 2018 : Debug: including dictionary file /usr/local/share/freeradius/dictionary.dhcp Sun Feb 4 18:40:52 2018 : Debug: including dictionary file /usr/local/share/freeradius/dictionary.vqp Sun Feb 4 18:40:52 2018 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/clients.conf Sun Feb 4 18:40:52 2018 : Debug: including files in directory /usr/local/etc/raddb/mods-enabled/ Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/utf8 Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/dynamic_clients Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/expiration Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/replicate Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/linelog Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/preprocess Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/soh Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/detail Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/eap Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/passwd Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/logintime Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/mschap Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/chap Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/date Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/pap Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/unix Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/unpack Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/expr Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/exec Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/echo Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/digest Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/files Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/radutmp Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap Sun Feb 4 18:40:52 2018 : Debug: including files in directory /usr/local/etc/raddb/policy.d/ Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/moonshot-targeted-ids Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/control Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/abfab-tr Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/eap Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/accounting Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/filter Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/dhcp Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/cui Sun Feb 4 18:40:52 2018 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Sun Feb 4 18:40:52 2018 : Debug: OPTIMIZING (no == yes) --> FALSE Sun Feb 4 18:40:52 2018 : Debug: OPTIMIZING (${policy.cui_require_operator_name} == yes) --> FALSE Sun Feb 4 18:40:52 2018 : Debug: OPTIMIZING (no == yes) --> FALSE Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/debug Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/operator-name Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/policy.d/canonicalization Sun Feb 4 18:40:52 2018 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/ Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel Sun Feb 4 18:40:52 2018 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default Sun Feb 4 18:40:52 2018 : Debug: main { Sun Feb 4 18:40:52 2018 : Debug: security { Sun Feb 4 18:40:52 2018 : Debug: allow_core_dumps = no Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[424]: The item 'max_attributes' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[442]: The item 'reject_delay' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[462]: The item 'status_server' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[472]: The item 'allow_vulnerable_openssl' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: name = "radiusd" Sun Feb 4 18:40:52 2018 : Debug: prefix = "/usr/local" Sun Feb 4 18:40:52 2018 : Debug: localstatedir = "/usr/local/var" Sun Feb 4 18:40:52 2018 : Debug: logdir = "/usr/local/var/log/radius" Sun Feb 4 18:40:52 2018 : Debug: run_dir = "/usr/local/var/run/radiusd" Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[108]: The item 'libdir' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[119]: The item 'pidfile' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[194]: The item 'max_request_time' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[213]: The item 'cleanup_delay' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[250]: The item 'hostname_lookups' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[334]: The item 'checkrad' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[491]: The item 'proxy_requests' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: main { Sun Feb 4 18:40:52 2018 : Debug: name = "radiusd" Sun Feb 4 18:40:52 2018 : Debug: prefix = "/usr/local" Sun Feb 4 18:40:52 2018 : Debug: localstatedir = "/usr/local/var" Sun Feb 4 18:40:52 2018 : Debug: sbindir = "/usr/local/sbin" Sun Feb 4 18:40:52 2018 : Debug: logdir = "/usr/local/var/log/radius" Sun Feb 4 18:40:52 2018 : Debug: run_dir = "/usr/local/var/run/radiusd" Sun Feb 4 18:40:52 2018 : Debug: libdir = "/usr/local/lib" Sun Feb 4 18:40:52 2018 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Sun Feb 4 18:40:52 2018 : Debug: hostname_lookups = no Sun Feb 4 18:40:52 2018 : Debug: max_request_time = 30 Sun Feb 4 18:40:52 2018 : Debug: cleanup_delay = 5 Sun Feb 4 18:40:52 2018 : Debug: max_requests = 16384 Sun Feb 4 18:40:52 2018 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Sun Feb 4 18:40:52 2018 : Debug: checkrad = "/usr/local/sbin/checkrad" Sun Feb 4 18:40:52 2018 : Debug: debug_level = 0 Sun Feb 4 18:40:52 2018 : Debug: proxy_requests = yes Sun Feb 4 18:40:52 2018 : Debug: log { Sun Feb 4 18:40:52 2018 : Debug: stripped_names = no Sun Feb 4 18:40:52 2018 : Debug: auth = no Sun Feb 4 18:40:52 2018 : Debug: auth_badpass = no Sun Feb 4 18:40:52 2018 : Debug: auth_goodpass = no Sun Feb 4 18:40:52 2018 : Debug: colourise = yes Sun Feb 4 18:40:52 2018 : Debug: msg_denied = "You are already logged in - access denied" Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[268]: The item 'destination' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[285]: The item 'file' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[293]: The item 'syslog_facility' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: resources { Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: security { Sun Feb 4 18:40:52 2018 : Debug: max_attributes = 200 Sun Feb 4 18:40:52 2018 : Debug: reject_delay = 1.000000 Sun Feb 4 18:40:52 2018 : Debug: status_server = yes Sun Feb 4 18:40:52 2018 : Debug: allow_vulnerable_openssl = "yes" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[67]: The item 'confdir' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[74]: The item 'db_dir' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Warning: /usr/local/etc/raddb/radiusd.conf[140]: The item 'correct_escapes' is defined, but is unused by the configuration Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: radiusd: #### Loading Realms and Home Servers #### Sun Feb 4 18:40:52 2018 : Debug: proxy server { Sun Feb 4 18:40:52 2018 : Debug: retry_delay = 5 Sun Feb 4 18:40:52 2018 : Debug: retry_count = 3 Sun Feb 4 18:40:52 2018 : Debug: default_fallback = no Sun Feb 4 18:40:52 2018 : Debug: dead_time = 120 Sun Feb 4 18:40:52 2018 : Debug: wake_all_if_all_dead = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: home_server localhost { Sun Feb 4 18:40:52 2018 : Debug: ipaddr = 127.0.0.1 Sun Feb 4 18:40:52 2018 : Debug: port = 1812 Sun Feb 4 18:40:52 2018 : Debug: type = "auth" Sun Feb 4 18:40:52 2018 : Debug: secret = "testing123" Sun Feb 4 18:40:52 2018 : Debug: response_window = 20.000000 Sun Feb 4 18:40:52 2018 : Debug: response_timeouts = 1 Sun Feb 4 18:40:52 2018 : Debug: max_outstanding = 65536 Sun Feb 4 18:40:52 2018 : Debug: zombie_period = 40 Sun Feb 4 18:40:52 2018 : Debug: status_check = "status-server" Sun Feb 4 18:40:52 2018 : Debug: ping_interval = 30 Sun Feb 4 18:40:52 2018 : Debug: check_interval = 30 Sun Feb 4 18:40:52 2018 : Debug: check_timeout = 4 Sun Feb 4 18:40:52 2018 : Debug: num_answers_to_alive = 3 Sun Feb 4 18:40:52 2018 : Debug: revive_interval = 120 Sun Feb 4 18:40:52 2018 : Debug: limit { Sun Feb 4 18:40:52 2018 : Debug: max_connections = 16 Sun Feb 4 18:40:52 2018 : Debug: max_requests = 0 Sun Feb 4 18:40:52 2018 : Debug: lifetime = 0 Sun Feb 4 18:40:52 2018 : Debug: idle_timeout = 0 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: coa { Sun Feb 4 18:40:52 2018 : Debug: irt = 2 Sun Feb 4 18:40:52 2018 : Debug: mrt = 16 Sun Feb 4 18:40:52 2018 : Debug: mrc = 5 Sun Feb 4 18:40:52 2018 : Debug: mrd = 30 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: home_server_pool my_auth_failover { Sun Feb 4 18:40:52 2018 : Debug: type = fail-over Sun Feb 4 18:40:52 2018 : Debug: home_server = localhost Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: realm example.com { Sun Feb 4 18:40:52 2018 : Debug: auth_pool = my_auth_failover Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: realm LOCAL { Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: radiusd: #### Loading Clients #### Sun Feb 4 18:40:52 2018 : Debug: client localhost { Sun Feb 4 18:40:52 2018 : Debug: ipaddr = 127.0.0.1 Sun Feb 4 18:40:52 2018 : Debug: require_message_authenticator = no Sun Feb 4 18:40:52 2018 : Debug: secret = "testing123" Sun Feb 4 18:40:52 2018 : Debug: nas_type = "other" Sun Feb 4 18:40:52 2018 : Debug: proto = "*" Sun Feb 4 18:40:52 2018 : Debug: limit { Sun Feb 4 18:40:52 2018 : Debug: max_connections = 16 Sun Feb 4 18:40:52 2018 : Debug: lifetime = 0 Sun Feb 4 18:40:52 2018 : Debug: idle_timeout = 30 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32 Sun Feb 4 18:40:52 2018 : Info: Found debugger attached Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = mschap Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = eap Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = PAP Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = CHAP Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = MS-CHAP Sun Feb 4 18:40:52 2018 : Debug: # Creating Auth-Type = digest Sun Feb 4 18:40:52 2018 : Debug: radiusd: #### Instantiating modules #### Sun Feb 4 18:40:52 2018 : Debug: modules { Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_utf8 with path: /usr/local/lib/rlm_utf8.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_utf8, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_utf8 Sun Feb 4 18:40:52 2018 : Debug: # Loading module "utf8" from file /usr/local/etc/raddb/mods-enabled/utf8 Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_dynamic_clients with path: /usr/local/lib/rlm_dynamic_clients.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_dynamic_clients, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_dynamic_clients Sun Feb 4 18:40:52 2018 : Debug: # Loading module "dynamic_clients" from file /usr/local/etc/raddb/mods-enabled/dynamic_clients Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_expiration with path: /usr/local/lib/rlm_expiration.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_expiration, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_expiration Sun Feb 4 18:40:52 2018 : Debug: # Loading module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_replicate with path: /usr/local/lib/rlm_replicate.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_replicate, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_replicate Sun Feb 4 18:40:52 2018 : Debug: # Loading module "replicate" from file /usr/local/etc/raddb/mods-enabled/replicate Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_linelog with path: /usr/local/lib/rlm_linelog.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_linelog, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_linelog Sun Feb 4 18:40:52 2018 : Debug: # Loading module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog Sun Feb 4 18:40:52 2018 : Debug: linelog { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/linelog" Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: syslog_severity = "info" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: format = "This is a log message for %{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: reference = "messages.%{%{reply:Packet-Type}:-default}" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog Sun Feb 4 18:40:52 2018 : Debug: linelog log_accounting { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/linelog-accounting" Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: syslog_severity = "info" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: format = "" Sun Feb 4 18:40:52 2018 : Debug: reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_realm with path: /usr/local/lib/rlm_realm.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_realm, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_realm Sun Feb 4 18:40:52 2018 : Debug: # Loading module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: realm IPASS { Sun Feb 4 18:40:52 2018 : Debug: format = "prefix" Sun Feb 4 18:40:52 2018 : Debug: delimiter = "/" Sun Feb 4 18:40:52 2018 : Debug: ignore_default = no Sun Feb 4 18:40:52 2018 : Debug: ignore_null = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: realm suffix { Sun Feb 4 18:40:52 2018 : Debug: format = "suffix" Sun Feb 4 18:40:52 2018 : Debug: delimiter = "@" Sun Feb 4 18:40:52 2018 : Debug: ignore_default = no Sun Feb 4 18:40:52 2018 : Debug: ignore_null = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: realm realmpercent { Sun Feb 4 18:40:52 2018 : Debug: format = "suffix" Sun Feb 4 18:40:52 2018 : Debug: delimiter = "%" Sun Feb 4 18:40:52 2018 : Debug: ignore_default = no Sun Feb 4 18:40:52 2018 : Debug: ignore_null = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: realm ntdomain { Sun Feb 4 18:40:52 2018 : Debug: format = "prefix" Sun Feb 4 18:40:52 2018 : Debug: delimiter = "\\" Sun Feb 4 18:40:52 2018 : Debug: ignore_default = no Sun Feb 4 18:40:52 2018 : Debug: ignore_null = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_preprocess with path: /usr/local/lib/rlm_preprocess.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_preprocess, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_preprocess Sun Feb 4 18:40:52 2018 : Debug: # Loading module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess Sun Feb 4 18:40:52 2018 : Debug: preprocess { Sun Feb 4 18:40:52 2018 : Debug: huntgroups = "/usr/local/etc/raddb/mods-config/preprocess/huntgroups" Sun Feb 4 18:40:52 2018 : Debug: hints = "/usr/local/etc/raddb/mods-config/preprocess/hints" Sun Feb 4 18:40:52 2018 : Debug: with_ascend_hack = no Sun Feb 4 18:40:52 2018 : Debug: ascend_channels_per_line = 23 Sun Feb 4 18:40:52 2018 : Debug: with_ntdomain_hack = no Sun Feb 4 18:40:52 2018 : Debug: with_specialix_jetstream_hack = no Sun Feb 4 18:40:52 2018 : Debug: with_cisco_vsa_hack = no Sun Feb 4 18:40:52 2018 : Debug: with_alvarion_vsa_hack = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_soh with path: /usr/local/lib/rlm_soh.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_soh, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_soh Sun Feb 4 18:40:52 2018 : Debug: # Loading module "soh" from file /usr/local/etc/raddb/mods-enabled/soh Sun Feb 4 18:40:52 2018 : Debug: soh { Sun Feb 4 18:40:52 2018 : Debug: dhcp = yes Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_detail with path: /usr/local/lib/rlm_detail.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_detail, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_detail Sun Feb 4 18:40:52 2018 : Debug: # Loading module "detail" from file /usr/local/etc/raddb/mods-enabled/detail Sun Feb 4 18:40:52 2018 : Debug: detail { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" Sun Feb 4 18:40:52 2018 : Debug: header = "%t" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: locking = no Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: log_packet_header = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_radutmp with path: /usr/local/lib/rlm_radutmp.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_radutmp, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_radutmp Sun Feb 4 18:40:52 2018 : Debug: # Loading module "sradutmp" from file /usr/local/etc/raddb/mods-enabled/sradutmp Sun Feb 4 18:40:52 2018 : Debug: radutmp sradutmp { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/sradutmp" Sun Feb 4 18:40:52 2018 : Debug: username = "%{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: case_sensitive = yes Sun Feb 4 18:40:52 2018 : Debug: check_with_nas = yes Sun Feb 4 18:40:52 2018 : Debug: permissions = 420 Sun Feb 4 18:40:52 2018 : Debug: caller_id = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap with path: /usr/local/lib/rlm_eap.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_eap, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_eap Sun Feb 4 18:40:52 2018 : Debug: # Loading module "eap" from file /usr/local/etc/raddb/mods-enabled/eap Sun Feb 4 18:40:52 2018 : Debug: eap { Sun Feb 4 18:40:52 2018 : Debug: default_eap_type = "md5" Sun Feb 4 18:40:52 2018 : Debug: timer_expire = 60 Sun Feb 4 18:40:52 2018 : Debug: ignore_unknown_eap_types = no Sun Feb 4 18:40:52 2018 : Debug: cisco_accounting_username_bug = no Sun Feb 4 18:40:52 2018 : Debug: max_sessions = 16384 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_passwd with path: /usr/local/lib/rlm_passwd.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_passwd, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_passwd Sun Feb 4 18:40:52 2018 : Debug: # Loading module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd Sun Feb 4 18:40:52 2018 : Debug: passwd etc_passwd { Sun Feb 4 18:40:52 2018 : Debug: filename = "/etc/passwd" Sun Feb 4 18:40:52 2018 : Debug: format = "*User-Name:Crypt-Password:" Sun Feb 4 18:40:52 2018 : Debug: delimiter = ":" Sun Feb 4 18:40:52 2018 : Debug: ignore_nislike = no Sun Feb 4 18:40:52 2018 : Debug: ignore_empty = yes Sun Feb 4 18:40:52 2018 : Debug: allow_multiple_keys = no Sun Feb 4 18:40:52 2018 : Debug: hash_size = 100 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_logintime with path: /usr/local/lib/rlm_logintime.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_logintime, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_logintime Sun Feb 4 18:40:52 2018 : Debug: # Loading module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime Sun Feb 4 18:40:52 2018 : Debug: logintime { Sun Feb 4 18:40:52 2018 : Debug: minimum_timeout = 60 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_mschap with path: /usr/local/lib/rlm_mschap.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_mschap, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_mschap Sun Feb 4 18:40:52 2018 : Debug: # Loading module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap Sun Feb 4 18:40:52 2018 : Debug: mschap { Sun Feb 4 18:40:52 2018 : Debug: use_mppe = yes Sun Feb 4 18:40:52 2018 : Debug: require_encryption = no Sun Feb 4 18:40:52 2018 : Debug: require_strong = no Sun Feb 4 18:40:52 2018 : Debug: with_ntdomain_hack = yes Sun Feb 4 18:40:52 2018 : Debug: passchange { Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: allow_retry = yes Sun Feb 4 18:40:52 2018 : Debug: winbind_retry_with_normalised_username = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_chap with path: /usr/local/lib/rlm_chap.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_chap, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_chap Sun Feb 4 18:40:52 2018 : Debug: # Loading module "chap" from file /usr/local/etc/raddb/mods-enabled/chap Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_date with path: /usr/local/lib/rlm_date.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_date, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_date Sun Feb 4 18:40:52 2018 : Debug: # Loading module "date" from file /usr/local/etc/raddb/mods-enabled/date Sun Feb 4 18:40:52 2018 : Debug: date { Sun Feb 4 18:40:52 2018 : Debug: format = "%b %e %Y %H:%M:%S %Z" Sun Feb 4 18:40:52 2018 : Debug: utc = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_always with path: /usr/local/lib/rlm_always.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_always, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_always Sun Feb 4 18:40:52 2018 : Debug: # Loading module "reject" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always reject { Sun Feb 4 18:40:52 2018 : Debug: rcode = "reject" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "fail" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always fail { Sun Feb 4 18:40:52 2018 : Debug: rcode = "fail" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "ok" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always ok { Sun Feb 4 18:40:52 2018 : Debug: rcode = "ok" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "handled" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always handled { Sun Feb 4 18:40:52 2018 : Debug: rcode = "handled" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "invalid" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always invalid { Sun Feb 4 18:40:52 2018 : Debug: rcode = "invalid" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "userlock" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always userlock { Sun Feb 4 18:40:52 2018 : Debug: rcode = "userlock" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "notfound" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always notfound { Sun Feb 4 18:40:52 2018 : Debug: rcode = "notfound" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "noop" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always noop { Sun Feb 4 18:40:52 2018 : Debug: rcode = "noop" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "updated" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: always updated { Sun Feb 4 18:40:52 2018 : Debug: rcode = "updated" Sun Feb 4 18:40:52 2018 : Debug: simulcount = 0 Sun Feb 4 18:40:52 2018 : Debug: mpp = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_pap with path: /usr/local/lib/rlm_pap.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_pap, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_pap Sun Feb 4 18:40:52 2018 : Debug: # Loading module "pap" from file /usr/local/etc/raddb/mods-enabled/pap Sun Feb 4 18:40:52 2018 : Debug: pap { Sun Feb 4 18:40:52 2018 : Debug: normalise = yes Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: detail auth_log { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" Sun Feb 4 18:40:52 2018 : Debug: header = "%t" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: locking = no Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: log_packet_header = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: detail reply_log { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" Sun Feb 4 18:40:52 2018 : Debug: header = "%t" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: locking = no Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: log_packet_header = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: detail pre_proxy_log { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" Sun Feb 4 18:40:52 2018 : Debug: header = "%t" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: locking = no Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: log_packet_header = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: detail post_proxy_log { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" Sun Feb 4 18:40:52 2018 : Debug: header = "%t" Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: locking = no Sun Feb 4 18:40:52 2018 : Debug: escape_filenames = no Sun Feb 4 18:40:52 2018 : Debug: log_packet_header = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_unix with path: /usr/local/lib/rlm_unix.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_unix, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_unix Sun Feb 4 18:40:52 2018 : Debug: # Loading module "unix" from file /usr/local/etc/raddb/mods-enabled/unix Sun Feb 4 18:40:52 2018 : Debug: unix { Sun Feb 4 18:40:52 2018 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Creating attribute Unix-Group Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_exec with path: /usr/local/lib/rlm_exec.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_exec, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_exec Sun Feb 4 18:40:52 2018 : Debug: # Loading module "ntlm_auth" from file /usr/local/etc/raddb/mods-enabled/ntlm_auth Sun Feb 4 18:40:52 2018 : Debug: exec ntlm_auth { Sun Feb 4 18:40:52 2018 : Debug: wait = yes Sun Feb 4 18:40:52 2018 : Debug: program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" Sun Feb 4 18:40:52 2018 : Debug: shell_escape = yes Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_unpack with path: /usr/local/lib/rlm_unpack.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_unpack, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_unpack Sun Feb 4 18:40:52 2018 : Debug: # Loading module "unpack" from file /usr/local/etc/raddb/mods-enabled/unpack Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_attr_filter with path: /usr/local/lib/rlm_attr_filter.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_attr_filter, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_attr_filter Sun Feb 4 18:40:52 2018 : Debug: # Loading module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: attr_filter attr_filter.post-proxy { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy" Sun Feb 4 18:40:52 2018 : Debug: key = "%{Realm}" Sun Feb 4 18:40:52 2018 : Debug: relaxed = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: attr_filter attr_filter.pre-proxy { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy" Sun Feb 4 18:40:52 2018 : Debug: key = "%{Realm}" Sun Feb 4 18:40:52 2018 : Debug: relaxed = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: attr_filter attr_filter.access_reject { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject" Sun Feb 4 18:40:52 2018 : Debug: key = "%{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: relaxed = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: attr_filter attr_filter.access_challenge { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge" Sun Feb 4 18:40:52 2018 : Debug: key = "%{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: relaxed = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: attr_filter attr_filter.accounting_response { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response" Sun Feb 4 18:40:52 2018 : Debug: key = "%{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: relaxed = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_expr with path: /usr/local/lib/rlm_expr.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_expr, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_expr Sun Feb 4 18:40:52 2018 : Debug: # Loading module "expr" from file /usr/local/etc/raddb/mods-enabled/expr Sun Feb 4 18:40:52 2018 : Debug: expr { Sun Feb 4 18:40:52 2018 : Debug: safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "exec" from file /usr/local/etc/raddb/mods-enabled/exec Sun Feb 4 18:40:52 2018 : Debug: exec { Sun Feb 4 18:40:52 2018 : Debug: wait = no Sun Feb 4 18:40:52 2018 : Debug: input_pairs = "request" Sun Feb 4 18:40:52 2018 : Debug: shell_escape = yes Sun Feb 4 18:40:52 2018 : Debug: timeout = 10 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "echo" from file /usr/local/etc/raddb/mods-enabled/echo Sun Feb 4 18:40:52 2018 : Debug: exec echo { Sun Feb 4 18:40:52 2018 : Debug: wait = yes Sun Feb 4 18:40:52 2018 : Debug: program = "/bin/echo %{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: input_pairs = "request" Sun Feb 4 18:40:52 2018 : Debug: output_pairs = "reply" Sun Feb 4 18:40:52 2018 : Debug: shell_escape = yes Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_digest with path: /usr/local/lib/rlm_digest.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_digest, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_digest Sun Feb 4 18:40:52 2018 : Debug: # Loading module "digest" from file /usr/local/etc/raddb/mods-enabled/digest Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_files with path: /usr/local/lib/rlm_files.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_files, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_files Sun Feb 4 18:40:52 2018 : Debug: # Loading module "files" from file /usr/local/etc/raddb/mods-enabled/files Sun Feb 4 18:40:52 2018 : Debug: files { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/etc/raddb/mods-config/files/authorize" Sun Feb 4 18:40:52 2018 : Debug: acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting" Sun Feb 4 18:40:52 2018 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Loading module "radutmp" from file /usr/local/etc/raddb/mods-enabled/radutmp Sun Feb 4 18:40:52 2018 : Debug: radutmp { Sun Feb 4 18:40:52 2018 : Debug: filename = "/usr/local/var/log/radius/radutmp" Sun Feb 4 18:40:52 2018 : Debug: username = "%{User-Name}" Sun Feb 4 18:40:52 2018 : Debug: case_sensitive = yes Sun Feb 4 18:40:52 2018 : Debug: check_with_nas = yes Sun Feb 4 18:40:52 2018 : Debug: permissions = 384 Sun Feb 4 18:40:52 2018 : Debug: caller_id = yes Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_cache with path: /usr/local/lib/rlm_cache.so Sun Feb 4 18:40:52 2018 : Debug: Loaded rlm_cache, checking if it's valid Sun Feb 4 18:40:52 2018 : Debug: # Loaded module rlm_cache Sun Feb 4 18:40:52 2018 : Debug: # Loading module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap Sun Feb 4 18:40:52 2018 : Debug: cache cache_eap { Sun Feb 4 18:40:52 2018 : Debug: driver = "rlm_cache_rbtree" Sun Feb 4 18:40:52 2018 : Debug: key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" Sun Feb 4 18:40:52 2018 : Debug: ttl = 15 Sun Feb 4 18:40:52 2018 : Debug: max_entries = 0 Sun Feb 4 18:40:52 2018 : Debug: epoch = 0 Sun Feb 4 18:40:52 2018 : Debug: add_stats = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: instantiate { Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "expiration" from file /usr/local/etc/raddb/mods-enabled/expiration Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "linelog" from file /usr/local/etc/raddb/mods-enabled/linelog Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "log_accounting" from file /usr/local/etc/raddb/mods-enabled/linelog Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "IPASS" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "suffix" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "realmpercent" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "ntdomain" from file /usr/local/etc/raddb/mods-enabled/realm Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/huntgroups Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/preprocess/hints Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "detail" from file /usr/local/etc/raddb/mods-enabled/detail Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "eap" from file /usr/local/etc/raddb/mods-enabled/eap Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_md5 with path: /usr/local/lib/rlm_eap_md5.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_md5 Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_leap with path: /usr/local/lib/rlm_eap_leap.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_leap Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_gtc with path: /usr/local/lib/rlm_eap_gtc.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_gtc Sun Feb 4 18:40:52 2018 : Debug: gtc { Sun Feb 4 18:40:52 2018 : Debug: challenge = "Password: " Sun Feb 4 18:40:52 2018 : Debug: auth_type = "PAP" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_tls with path: /usr/local/lib/rlm_eap_tls.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_tls Sun Feb 4 18:40:52 2018 : Debug: tls { Sun Feb 4 18:40:52 2018 : Debug: tls = "tls-common" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: tls-config tls-common { Sun Feb 4 18:40:52 2018 : Debug: verify_depth = 0 Sun Feb 4 18:40:52 2018 : Debug: ca_path = "/usr/local/etc/raddb/certs" Sun Feb 4 18:40:52 2018 : Debug: pem_file_type = yes Sun Feb 4 18:40:52 2018 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem" Sun Feb 4 18:40:52 2018 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem" Sun Feb 4 18:40:52 2018 : Debug: ca_file = "/usr/local/etc/raddb/certs/frenche.ca.chain.pem" Sun Feb 4 18:40:52 2018 : Debug: private_key_password = "whatever" Sun Feb 4 18:40:52 2018 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Sun Feb 4 18:40:52 2018 : Debug: fragment_size = 1024 Sun Feb 4 18:40:52 2018 : Debug: include_length = yes Sun Feb 4 18:40:52 2018 : Debug: auto_chain = yes Sun Feb 4 18:40:52 2018 : Debug: check_crl = no Sun Feb 4 18:40:52 2018 : Debug: check_all_crl = no Sun Feb 4 18:40:52 2018 : Debug: cipher_list = "DEFAULT" Sun Feb 4 18:40:52 2018 : Debug: cipher_server_preference = no Sun Feb 4 18:40:52 2018 : Debug: ecdh_curve = "prime256v1" Sun Feb 4 18:40:52 2018 : Debug: tls_max_version = "" Sun Feb 4 18:40:52 2018 : Debug: tls_min_version = "1.0" Sun Feb 4 18:40:52 2018 : Debug: cache { Sun Feb 4 18:40:52 2018 : Debug: enable = no Sun Feb 4 18:40:52 2018 : Debug: lifetime = 24 Sun Feb 4 18:40:52 2018 : Debug: max_entries = 255 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: verify { Sun Feb 4 18:40:52 2018 : Debug: skip_if_ocsp_ok = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: ocsp { Sun Feb 4 18:40:52 2018 : Debug: enable = yes Sun Feb 4 18:40:52 2018 : Debug: override_cert_url = yes Sun Feb 4 18:40:52 2018 : Debug: url = "http://127.0.0.1/ocsp/" Sun Feb 4 18:40:52 2018 : Debug: use_nonce = yes Sun Feb 4 18:40:52 2018 : Debug: timeout = 0 Sun Feb 4 18:40:52 2018 : Debug: softfail = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_ttls with path: /usr/local/lib/rlm_eap_ttls.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_ttls Sun Feb 4 18:40:52 2018 : Debug: ttls { Sun Feb 4 18:40:52 2018 : Debug: tls = "tls-common" Sun Feb 4 18:40:52 2018 : Debug: default_eap_type = "md5" Sun Feb 4 18:40:52 2018 : Debug: copy_request_to_tunnel = no Sun Feb 4 18:40:52 2018 : Debug: use_tunneled_reply = no Sun Feb 4 18:40:52 2018 : Debug: virtual_server = "inner-tunnel" Sun Feb 4 18:40:52 2018 : Debug: include_length = yes Sun Feb 4 18:40:52 2018 : Debug: require_client_cert = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: tls: Using cached TLS configuration from previous invocation Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_peap with path: /usr/local/lib/rlm_eap_peap.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_peap Sun Feb 4 18:40:52 2018 : Debug: peap { Sun Feb 4 18:40:52 2018 : Debug: tls = "tls-common" Sun Feb 4 18:40:52 2018 : Debug: default_eap_type = "mschapv2" Sun Feb 4 18:40:52 2018 : Debug: copy_request_to_tunnel = no Sun Feb 4 18:40:52 2018 : Debug: use_tunneled_reply = no Sun Feb 4 18:40:52 2018 : Debug: proxy_tunneled_request_as_eap = yes Sun Feb 4 18:40:52 2018 : Debug: virtual_server = "inner-tunnel" Sun Feb 4 18:40:52 2018 : Debug: soh = no Sun Feb 4 18:40:52 2018 : Debug: require_client_cert = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: tls: Using cached TLS configuration from previous invocation Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_eap_mschapv2 with path: /usr/local/lib/rlm_eap_mschapv2.so Sun Feb 4 18:40:52 2018 : Debug: # Linked to sub-module rlm_eap_mschapv2 Sun Feb 4 18:40:52 2018 : Debug: mschapv2 { Sun Feb 4 18:40:52 2018 : Debug: with_ntdomain_hack = no Sun Feb 4 18:40:52 2018 : Debug: send_error = no Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "etc_passwd" from file /usr/local/etc/raddb/mods-enabled/passwd Sun Feb 4 18:40:52 2018 : Debug: rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "logintime" from file /usr/local/etc/raddb/mods-enabled/logintime Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "mschap" from file /usr/local/etc/raddb/mods-enabled/mschap Sun Feb 4 18:40:52 2018 : Debug: rlm_mschap (mschap): using internal authentication Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "reject" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "fail" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "ok" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "handled" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "invalid" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "userlock" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "notfound" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "noop" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "updated" from file /usr/local/etc/raddb/mods-enabled/always Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "pap" from file /usr/local/etc/raddb/mods-enabled/pap Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "auth_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "reply_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "pre_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "post_proxy_log" from file /usr/local/etc/raddb/mods-enabled/detail.log Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "attr_filter.post-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_reject Sun Feb 4 18:40:52 2018 : Warning: [/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". Sun Feb 4 18:40:52 2018 : Warning: [/usr/local/etc/raddb/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "attr_filter.access_challenge" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/mods-enabled/attr_filter Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "files" from file /usr/local/etc/raddb/mods-enabled/files Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/authorize Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/accounting Sun Feb 4 18:40:52 2018 : Debug: reading pairlist file /usr/local/etc/raddb/mods-config/files/pre-proxy Sun Feb 4 18:40:52 2018 : Debug: # Instantiating module "cache_eap" from file /usr/local/etc/raddb/mods-enabled/cache_eap Sun Feb 4 18:40:52 2018 : Debug: Loading rlm_cache_rbtree with path: /usr/local/lib/rlm_cache_rbtree.so Sun Feb 4 18:40:52 2018 : Debug: rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked Sun Feb 4 18:40:52 2018 : Debug: } # modules Sun Feb 4 18:40:52 2018 : Debug: radiusd: #### Loading Virtual Servers #### Sun Feb 4 18:40:52 2018 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Sun Feb 4 18:40:52 2018 : Debug: } # server Sun Feb 4 18:40:52 2018 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Sun Feb 4 18:40:52 2018 : Debug: authenticate { Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: pap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: chap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: } # authenticate Sun Feb 4 18:40:52 2018 : Debug: authorize { Sun Feb 4 18:40:52 2018 : Debug: policy filter_username { Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name) { Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ / /) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@[^@]*@/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /\.\./) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /\.$/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@\./) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: chap Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: suffix Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &control:Proxy-To-Realm := LOCAL Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: files Sun Feb 4 18:40:52 2018 : Warning: Ignoring "sql" (see raddb/mods-available/README.rst) Sun Feb 4 18:40:52 2018 : Warning: Ignoring "ldap" (see raddb/mods-available/README.rst) Sun Feb 4 18:40:52 2018 : Debug: expiration Sun Feb 4 18:40:52 2018 : Debug: logintime Sun Feb 4 18:40:52 2018 : Debug: pap Sun Feb 4 18:40:52 2018 : Debug: } # authorize Sun Feb 4 18:40:52 2018 : Debug: session { Sun Feb 4 18:40:52 2018 : Debug: radutmp Sun Feb 4 18:40:52 2018 : Debug: } # session Sun Feb 4 18:40:52 2018 : Debug: post-proxy { Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: } # post-proxy Sun Feb 4 18:40:52 2018 : Debug: post-auth { Sun Feb 4 18:40:52 2018 : Info: # Skipping contents of 'if' as it is always 'false' -- /usr/local/etc/raddb/sites-enabled/inner-tunnel:331 Sun Feb 4 18:40:52 2018 : Debug: if (false) { Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: attr_filter.access_reject Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &outer.session-state:Module-Failure-Message := &Module-Failure-Message Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } # post-auth Sun Feb 4 18:40:52 2018 : Debug: } # server inner-tunnel Sun Feb 4 18:40:52 2018 : Debug: server default { # from file /usr/local/etc/raddb/sites-enabled/default Sun Feb 4 18:40:52 2018 : Debug: authenticate { Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: pap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: chap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: digest Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: } # authenticate Sun Feb 4 18:40:52 2018 : Debug: authorize { Sun Feb 4 18:40:52 2018 : Debug: policy filter_username { Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name) { Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ / /) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains whitespace' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@[^@]*@/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Multiple @ in User-Name' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /\.\./) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: User-Name contains multiple ..s' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@/ && !&User-Name =~ /@(.+)\.(.+)$/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm does not have at least one dot separator' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /\.$/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm ends with a dot' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if (&User-Name =~ /@\./) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Module-Failure-Message += 'Rejected: Realm begins with a dot' Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: reject Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: preprocess Sun Feb 4 18:40:52 2018 : Debug: chap Sun Feb 4 18:40:52 2018 : Debug: mschap Sun Feb 4 18:40:52 2018 : Debug: digest Sun Feb 4 18:40:52 2018 : Debug: suffix Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: files Sun Feb 4 18:40:52 2018 : Debug: expiration Sun Feb 4 18:40:52 2018 : Debug: logintime Sun Feb 4 18:40:52 2018 : Debug: pap Sun Feb 4 18:40:52 2018 : Debug: } # authorize Sun Feb 4 18:40:52 2018 : Debug: preacct { Sun Feb 4 18:40:52 2018 : Debug: preprocess Sun Feb 4 18:40:52 2018 : Debug: policy acct_unique { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Tmp-String-9 := "ai:" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: if ("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/ && "%{string:&Class}" =~ /^ai:([0-9a-f]{32})/) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Acct-Unique-Session-Id := "%{md5:%{1},%{Acct-Session-ID}}" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: else { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &Acct-Unique-Session-Id := "%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: suffix Sun Feb 4 18:40:52 2018 : Debug: files Sun Feb 4 18:40:52 2018 : Debug: } # preacct Sun Feb 4 18:40:52 2018 : Debug: accounting { Sun Feb 4 18:40:52 2018 : Debug: detail Sun Feb 4 18:40:52 2018 : Debug: unix Sun Feb 4 18:40:52 2018 : Debug: exec Sun Feb 4 18:40:52 2018 : Debug: attr_filter.accounting_response Sun Feb 4 18:40:52 2018 : Debug: } # accounting Sun Feb 4 18:40:52 2018 : Debug: post-proxy { Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: } # post-proxy Sun Feb 4 18:40:52 2018 : Debug: post-auth { Sun Feb 4 18:40:52 2018 : Debug: policy debug_all { Sun Feb 4 18:40:52 2018 : Debug: policy debug_control { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:control:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_request { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:request:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_coa { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:coa:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_reply { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:reply:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_session_state { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:session-state:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &reply:[*] += &session-state:[*] Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: exec Sun Feb 4 18:40:52 2018 : Debug: policy remove_reply_message_if_eap { Sun Feb 4 18:40:52 2018 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &reply:Reply-Message !* ANY Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: else { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: attr_filter.access_reject Sun Feb 4 18:40:52 2018 : Debug: eap Sun Feb 4 18:40:52 2018 : Debug: policy remove_reply_message_if_eap { Sun Feb 4 18:40:52 2018 : Debug: if (&reply:EAP-Message && &reply:Reply-Message) { Sun Feb 4 18:40:52 2018 : Debug: update { Sun Feb 4 18:40:52 2018 : Debug: &reply:Reply-Message !* ANY Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: else { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_all { Sun Feb 4 18:40:52 2018 : Debug: policy debug_control { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:control:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_request { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:request:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_coa { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:coa:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_reply { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:reply:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_session_state { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:session-state:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: group { Sun Feb 4 18:40:52 2018 : Debug: policy debug_all { Sun Feb 4 18:40:52 2018 : Debug: policy debug_control { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:control:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_request { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:request:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_coa { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:coa:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_reply { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:reply:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: policy debug_session_state { Sun Feb 4 18:40:52 2018 : Debug: if ("%{debug_attr:session-state:}" == ) { Sun Feb 4 18:40:52 2018 : Debug: noop Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } # post-auth Sun Feb 4 18:40:52 2018 : Debug: } # server default Sun Feb 4 18:40:52 2018 : Debug: Created signal pipe. Read end FD 5, write end FD 6 Sun Feb 4 18:40:52 2018 : Debug: radiusd: #### Opening IP addresses and Ports #### Sun Feb 4 18:40:52 2018 : Debug: Loading proto_auth with path: /usr/local/lib/proto_auth.so Sun Feb 4 18:40:52 2018 : Debug: Loading proto_auth failed: /usr/local/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Sun Feb 4 18:40:52 2018 : Debug: Loading library using linker search path(s) Sun Feb 4 18:40:52 2018 : Debug: LD_LIBRARY_PATH : /usr/local/lib64:/usr/local/lib Sun Feb 4 18:40:52 2018 : Debug: Defaults : /lib:/usr/lib Sun Feb 4 18:40:52 2018 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Sun Feb 4 18:40:52 2018 : Debug: listen { Sun Feb 4 18:40:52 2018 : Debug: type = "auth" Sun Feb 4 18:40:52 2018 : Debug: ipaddr = 127.0.0.1 Sun Feb 4 18:40:52 2018 : Debug: port = 18120 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading proto_auth with path: /usr/local/lib/proto_auth.so Sun Feb 4 18:40:52 2018 : Debug: Loading proto_auth failed: /usr/local/lib/proto_auth.so: cannot open shared object file: No such file or directory - No such file or directory Sun Feb 4 18:40:52 2018 : Debug: Loading library using linker search path(s) Sun Feb 4 18:40:52 2018 : Debug: LD_LIBRARY_PATH : /usr/local/lib64:/usr/local/lib Sun Feb 4 18:40:52 2018 : Debug: Defaults : /lib:/usr/lib Sun Feb 4 18:40:52 2018 : Debug: Failed with error: proto_auth.so: cannot open shared object file: No such file or directory Sun Feb 4 18:40:52 2018 : Debug: listen { Sun Feb 4 18:40:52 2018 : Debug: type = "auth" Sun Feb 4 18:40:52 2018 : Debug: ipaddr = * Sun Feb 4 18:40:52 2018 : Debug: port = 0 Sun Feb 4 18:40:52 2018 : Debug: limit { Sun Feb 4 18:40:52 2018 : Debug: max_connections = 16 Sun Feb 4 18:40:52 2018 : Debug: lifetime = 0 Sun Feb 4 18:40:52 2018 : Debug: idle_timeout = 30 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Loading proto_acct with path: /usr/local/lib/proto_acct.so Sun Feb 4 18:40:52 2018 : Debug: Loading proto_acct failed: /usr/local/lib/proto_acct.so: cannot open shared object file: No such file or directory - No such file or directory Sun Feb 4 18:40:52 2018 : Debug: Loading library using linker search path(s) Sun Feb 4 18:40:52 2018 : Debug: LD_LIBRARY_PATH : /usr/local/lib64:/usr/local/lib Sun Feb 4 18:40:52 2018 : Debug: Defaults : /lib:/usr/lib Sun Feb 4 18:40:52 2018 : Debug: Failed with error: proto_acct.so: cannot open shared object file: No such file or directory Sun Feb 4 18:40:52 2018 : Debug: listen { Sun Feb 4 18:40:52 2018 : Debug: type = "acct" Sun Feb 4 18:40:52 2018 : Debug: ipaddr = * Sun Feb 4 18:40:52 2018 : Debug: port = 0 Sun Feb 4 18:40:52 2018 : Debug: limit { Sun Feb 4 18:40:52 2018 : Debug: max_connections = 16 Sun Feb 4 18:40:52 2018 : Debug: lifetime = 0 Sun Feb 4 18:40:52 2018 : Debug: idle_timeout = 30 Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: } Sun Feb 4 18:40:52 2018 : Debug: Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Sun Feb 4 18:40:52 2018 : Debug: Listening on auth address * port 1812 bound to server default Sun Feb 4 18:40:52 2018 : Debug: Listening on acct address * port 1813 bound to server default Sun Feb 4 18:40:52 2018 : Debug: Opened new proxy socket 'proxy address * port 34868' Sun Feb 4 18:40:52 2018 : Debug: Listening on proxy address * port 34868 Sun Feb 4 18:40:52 2018 : Info: Ready to process requests Socket: 8 Proto: 0 Src IP: 127.0.0.1 port: 36295 Dst IP: 127.0.0.1 port: 1812 Code: (1) Access-Request Id: 83 Length: 129 Vector: 4af2f4289fbb2c21069a403495ec85bb Data: 01 05 62 6f 62 04 06 d4 53 9e 02 05 06 00 00 00 00 50 12 c7 e9 ef d4 56 dc ce ed 1f 38 8d 80 e4 e0 0f 30 1a 10 00000137 (311) 0b 0a 2e c2 05 38 b2 c7 a2 25 1a 3a 00000137 (311) 01 34 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0b 29 23 3d 7f 38 9f 12 24 b9 d0 12 e0 35 f6 2f ca 43 67 af 5f 6b b5 28 Sun Feb 4 18:40:56 2018 : Debug: (0) Received Access-Request Id 83 from 127.0.0.1:36295 to 127.0.0.1:1812 length 129 Sun Feb 4 18:40:56 2018 : Debug: (0) User-Name = "bob" Sun Feb 4 18:40:56 2018 : Debug: (0) NAS-IP-Address = 212.83.158.2 Sun Feb 4 18:40:56 2018 : Debug: (0) NAS-Port = 0 Sun Feb 4 18:40:56 2018 : Debug: (0) Message-Authenticator = 0xc7e9efd456dcceed1f388d80e4e00f30 Sun Feb 4 18:40:56 2018 : Debug: (0) MS-CHAP-Challenge = 0x2ec20538b2c7a225 Sun Feb 4 18:40:56 2018 : Debug: (0) MS-CHAP-Response = 0x00010000000000000000000000000000000000000000000000000b29233d7f389f1224b9d012e035f62fca4367af5f6bb528 Sun Feb 4 18:40:56 2018 : Debug: (0) session-state: No State attribute Sun Feb 4 18:40:56 2018 : Debug: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Sun Feb 4 18:40:56 2018 : Debug: (0) authorize { Sun Feb 4 18:40:56 2018 : Debug: (0) policy filter_username { Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name) { Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name) -> TRUE Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name) { Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ / /) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ / /) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /\.\./ ) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /\.\./ ) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /\.$/) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /\.$/) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /@\./) { Sun Feb 4 18:40:56 2018 : Debug: No matches Sun Feb 4 18:40:56 2018 : Debug: (0) if (&User-Name =~ /@\./) -> FALSE Sun Feb 4 18:40:56 2018 : Debug: (0) } # if (&User-Name) = notfound Sun Feb 4 18:40:56 2018 : Debug: (0) } # policy filter_username = notfound Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling preprocess (rlm_preprocess) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) Sun Feb 4 18:40:56 2018 : Debug: (0) [preprocess] = ok Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling chap (rlm_chap) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from chap (rlm_chap) Sun Feb 4 18:40:56 2018 : Debug: (0) [chap] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling mschap (rlm_mschap) Sun Feb 4 18:40:56 2018 : Debug: (0) mschap: Found MS-CHAP attributes. Setting 'Auth-Type = mschap' Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from mschap (rlm_mschap) Sun Feb 4 18:40:56 2018 : Debug: (0) [mschap] = ok Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling digest (rlm_digest) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from digest (rlm_digest) Sun Feb 4 18:40:56 2018 : Debug: (0) [digest] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling suffix (rlm_realm) Sun Feb 4 18:40:56 2018 : Debug: (0) suffix: Checking for suffix after "@" Sun Feb 4 18:40:56 2018 : Debug: (0) suffix: No '@' in User-Name = "bob", looking up realm NULL Sun Feb 4 18:40:56 2018 : Debug: (0) suffix: No such realm "NULL" Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from suffix (rlm_realm) Sun Feb 4 18:40:56 2018 : Debug: (0) [suffix] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling eap (rlm_eap) Sun Feb 4 18:40:56 2018 : Debug: (0) eap: No EAP-Message, not doing EAP Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from eap (rlm_eap) Sun Feb 4 18:40:56 2018 : Debug: (0) [eap] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling files (rlm_files) Sun Feb 4 18:40:56 2018 : Debug: (0) files: users: Matched entry bob at line 87 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: FROM 4 TO 0 MAX 4 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: Examining Reply-Message Sun Feb 4 18:40:56 2018 : Debug: Hello2, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: Parsed xlat tree: Sun Feb 4 18:40:56 2018 : Debug: literal --> Hello2, Sun Feb 4 18:40:56 2018 : Debug: attribute --> User-Name Sun Feb 4 18:40:56 2018 : Debug: (0) files: EXPAND Hello2, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: (0) files: --> Hello2, bob Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: APPENDING Reply-Message FROM 0 TO 0 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: Examining Reply-Message Sun Feb 4 18:40:56 2018 : Debug: Hello3, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: Parsed xlat tree: Sun Feb 4 18:40:56 2018 : Debug: literal --> Hello3, Sun Feb 4 18:40:56 2018 : Debug: attribute --> User-Name Sun Feb 4 18:40:56 2018 : Debug: (0) files: EXPAND Hello3, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: (0) files: --> Hello3, bob Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: APPENDING Reply-Message FROM 1 TO 0 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: Examining Reply-Message Sun Feb 4 18:40:56 2018 : Debug: Hello44, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: Parsed xlat tree: Sun Feb 4 18:40:56 2018 : Debug: literal --> Hello44, Sun Feb 4 18:40:56 2018 : Debug: attribute --> User-Name Sun Feb 4 18:40:56 2018 : Debug: (0) files: EXPAND Hello44, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: (0) files: --> Hello44, bob Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: APPENDING Reply-Message FROM 2 TO 0 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: Examining Reply-Message Sun Feb 4 18:40:56 2018 : Debug: Hello2222, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: Parsed xlat tree: Sun Feb 4 18:40:56 2018 : Debug: literal --> Hello2222, Sun Feb 4 18:40:56 2018 : Debug: attribute --> User-Name Sun Feb 4 18:40:56 2018 : Debug: (0) files: EXPAND Hello2222, %{User-Name} Sun Feb 4 18:40:56 2018 : Debug: (0) files: --> Hello2222, bob Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: APPENDING Reply-Message FROM 3 TO 0 Sun Feb 4 18:40:56 2018 : Debug: (0) files: ::: TO in 0 out 0 Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from files (rlm_files) Sun Feb 4 18:40:56 2018 : Debug: (0) [files] = ok Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling expiration (rlm_expiration) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from expiration (rlm_expiration) Sun Feb 4 18:40:56 2018 : Debug: (0) [expiration] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling logintime (rlm_logintime) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from logintime (rlm_logintime) Sun Feb 4 18:40:56 2018 : Debug: (0) [logintime] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: calling pap (rlm_pap) Sun Feb 4 18:40:56 2018 : WARNING: (0) pap: Auth-Type already set. Not setting to PAP Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authorize]: returned from pap (rlm_pap) Sun Feb 4 18:40:56 2018 : Debug: (0) [pap] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) } # authorize = ok Sun Feb 4 18:40:56 2018 : Debug: (0) Found Auth-Type = mschap Sun Feb 4 18:40:56 2018 : Debug: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Sun Feb 4 18:40:56 2018 : Debug: (0) authenticate { Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authenticate]: calling mschap (rlm_mschap) Sun Feb 4 18:40:56 2018 : Debug: (0) mschap: Found Cleartext-Password, hashing to create NT-Password Sun Feb 4 18:40:56 2018 : Debug: (0) mschap: Found Cleartext-Password, hashing to create LM-Password Sun Feb 4 18:40:56 2018 : Debug: (0) mschap: Client is using MS-CHAPv1 with NT-Password Sun Feb 4 18:40:56 2018 : Debug: (0) mschap: adding MS-CHAPv1 MPPE keys Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[authenticate]: returned from mschap (rlm_mschap) Sun Feb 4 18:40:56 2018 : Debug: (0) [mschap] = ok Sun Feb 4 18:40:56 2018 : Debug: (0) } # authenticate = ok Sun Feb 4 18:40:56 2018 : Debug: (0) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default Sun Feb 4 18:40:56 2018 : Debug: (0) post-auth { Sun Feb 4 18:40:56 2018 : Debug: (0) policy debug_all { Sun Feb 4 18:40:56 2018 : Debug: (0) policy debug_control { Sun Feb 4 18:40:56 2018 : Debug: (0) if ("%{debug_attr:control:}" == '') { Sun Feb 4 18:40:56 2018 : Debug: (0) EXPAND TMPL XLAT STRUCT Sun Feb 4 18:40:56 2018 : Info: (0) Attributes matching "control:" Sun Feb 4 18:40:56 2018 : Info: (0) &control:Auth-Type = mschap Sun Feb 4 18:40:56 2018 : Info: (0) Type : integer Sun Feb 4 18:40:56 2018 : Info: (0) Length : 4 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : mschap Sun Feb 4 18:40:56 2018 : Debug: (0) as ipaddr : 0.101.231.179 Sun Feb 4 18:40:56 2018 : Debug: (0) as date : Jan 1 1970 00:00:00 UTC Sun Feb 4 18:40:56 2018 : Debug: (0) as octets : 0x0065e7b3 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : ::/0 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : 6678451 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : 6678451 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 6678451 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 6678451 Sun Feb 4 18:40:56 2018 : Info: (0) &control:Cleartext-Password := aristo1 Sun Feb 4 18:40:56 2018 : Info: (0) Type : string Sun Feb 4 18:40:56 2018 : Info: (0) Length : 7 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as octets : 0x61726973746f31 Sun Feb 4 18:40:56 2018 : Debug: (0) as byte : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint8 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : 0 Sun Feb 4 18:40:56 2018 : Info: (0) &control:NT-Password = 0xefc86e9649eddc50c1c202e3fbed3760 Sun Feb 4 18:40:56 2018 : Info: (0) Type : octets Sun Feb 4 18:40:56 2018 : Info: (0) Length : 16 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 4022890134 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0xefc86e9649eddc50c1c202e3fbed3760 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6addr : efc8:6e96:49ed:dc50:c1c2:2e3:fbed:3760 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : 6e96:49ed:dc50:c1c2:2e3:fbed:3760:0/200 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 61384 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : -272077162 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 61384 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 4022890134 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : -272077162 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 17278181562171382864 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 17278181562171382864 Sun Feb 4 18:40:56 2018 : Info: (0) &control:LM-Password = 0xc007e3905f1d5f4aaad3b435b51404ee Sun Feb 4 18:40:56 2018 : Info: (0) Type : octets Sun Feb 4 18:40:56 2018 : Info: (0) Length : 16 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 3221742480 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0xc007e3905f1d5f4aaad3b435b51404ee Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6addr : c007:e390:5f1d:5f4a:aad3:b435:b514:4ee Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : e390:5f1d:5f4a:aad3:b435:b514:4ee:0/7 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 49159 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : -1073224816 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 49159 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 3221742480 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : -1073224816 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 13837278589329694538 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 13837278589329694538 Sun Feb 4 18:40:56 2018 : Debug: (0) EXPAND %{debug_attr:control:} Sun Feb 4 18:40:56 2018 : Debug: (0) --> Sun Feb 4 18:40:56 2018 : Debug: (0) if ("%{debug_attr:control:}" == '') -> TRUE Sun Feb 4 18:40:56 2018 : Debug: (0) if ("%{debug_attr:control:}" == '') { Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[post-auth]: calling noop (rlm_always) Sun Feb 4 18:40:56 2018 : Debug: (0) modsingle[post-auth]: returned from noop (rlm_always) Sun Feb 4 18:40:56 2018 : Debug: (0) [noop] = noop Sun Feb 4 18:40:56 2018 : Debug: (0) } # if ("%{debug_attr:control:}" == '') = noop Sun Feb 4 18:40:56 2018 : Debug: (0) } # policy debug_control = noop Sun Feb 4 18:40:56 2018 : Debug: (0) policy debug_request { Sun Feb 4 18:40:56 2018 : Debug: (0) if ("%{debug_attr:request:}" == '') { Sun Feb 4 18:40:56 2018 : Debug: (0) EXPAND TMPL XLAT STRUCT Sun Feb 4 18:40:56 2018 : Info: (0) Attributes matching "request:" Sun Feb 4 18:40:56 2018 : Info: (0) &request:User-Name = bob Sun Feb 4 18:40:56 2018 : Info: (0) Type : string Sun Feb 4 18:40:56 2018 : Info: (0) Length : 3 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as octets : 0x626f62 Sun Feb 4 18:40:56 2018 : Debug: (0) as byte : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint8 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : 0 Sun Feb 4 18:40:56 2018 : Info: (0) &request:NAS-IP-Address = 212.83.158.2 Sun Feb 4 18:40:56 2018 : Info: (0) Type : ipaddr Sun Feb 4 18:40:56 2018 : Info: (0) Length : 4 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 212.83.158.2 Sun Feb 4 18:40:56 2018 : Debug: (0) as date : Nov 18 2082 17:48:50 UTC Sun Feb 4 18:40:56 2018 : Debug: (0) as octets : 0xd4539e02 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6addr : ::ffff:212.83.158.2 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : ::ffff:212.83.158.2/128 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv4prefix : 212.83.158.2/32 Sun Feb 4 18:40:56 2018 : Debug: (0) as cidr : 212.83.158.2/32 Sun Feb 4 18:40:56 2018 : Info: (0) &request:NAS-Port = 0 Sun Feb 4 18:40:56 2018 : Info: (0) Type : integer Sun Feb 4 18:40:56 2018 : Info: (0) Length : 4 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipaddr : 0.0.0.0 Sun Feb 4 18:40:56 2018 : Debug: (0) as date : Jan 1 1970 00:00:00 UTC Sun Feb 4 18:40:56 2018 : Debug: (0) as octets : 0x00000000 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : ::/0 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 0 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 0 Sun Feb 4 18:40:56 2018 : Info: (0) &request:Message-Authenticator = 0xc7e9efd456dcceed1f388d80e4e00f30 Sun Feb 4 18:40:56 2018 : Info: (0) Type : octets Sun Feb 4 18:40:56 2018 : Info: (0) Length : 16 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 3353997268 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0xc7e9efd456dcceed1f388d80e4e00f30 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6addr : c7e9:efd4:56dc:ceed:1f38:8d80:e4e0:f30 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : efd4:56dc:ceed:1f38:8d80:e4e0:f30:0/233 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 51177 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : -940970028 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 51177 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 3353997268 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : -940970028 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 14405308578390658797 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 14405308578390658797 Sun Feb 4 18:40:56 2018 : Info: (0) &request:MS-CHAP-Challenge = 0x2ec20538b2c7a225 Sun Feb 4 18:40:56 2018 : Info: (0) Vendor : 311 (Microsoft) Sun Feb 4 18:40:56 2018 : Info: (0) Type : octets Sun Feb 4 18:40:56 2018 : Info: (0) Length : 8 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 784467256 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0x2ec20538b2c7a225 Sun Feb 4 18:40:56 2018 : Debug: (0) as ifid : 2ec2:538:b2c7:a225 Sun Feb 4 18:40:56 2018 : Debug: (0) as ipv6prefix : 538:b2c7:a225::/194 Sun Feb 4 18:40:56 2018 : Debug: (0) as short : 11970 Sun Feb 4 18:40:56 2018 : Debug: (0) as signed : 784467256 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint16 : 11970 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint32 : 784467256 Sun Feb 4 18:40:56 2018 : Debug: (0) as int32 : 784467256 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer64 : 3369261212302287397 Sun Feb 4 18:40:56 2018 : Debug: (0) as uint64 : 3369261212302287397 Sun Feb 4 18:40:56 2018 : Info: (0) &request:MS-CHAP-Response = 0x00010000000000000000000000000000000000000000000000000b29233d7f389f1224b9d012e035f62fca4367af5f6bb528 Sun Feb 4 18:40:56 2018 : Info: (0) Vendor : 311 (Microsoft) Sun Feb 4 18:40:56 2018 : Info: (0) Type : octets Sun Feb 4 18:40:56 2018 : Info: (0) Length : 50 Sun Feb 4 18:40:56 2018 : Debug: (0) as integer : 65536 Sun Feb 4 18:40:56 2018 : Debug: (0) as string : 0x00010000000000000000000000000000000000000000000000000b29233d7f389f1224b9d012e035f62fca4367af5f6bb528 *** Error in `/usr/local/sbin/radiusd': malloc(): memory corruption: 0x000000000096c690 *** *** Error in `/usr/local/sbin/radiusd': malloc(): memory corruption: 0x000000000096c690 *** ^C Program received signal SIGINT, Interrupt. 0x00007ffff632db28 in pthread_once () from /lib64/libpthread.so.0 Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.6-14.fc21.x86_64 elfutils-libelf-0.163-4.fc21.x86_64 elfutils-libs-0.163-4.fc21.x86_64 libgcc-4.9.2-6.fc21.x86_64 libtalloc-2.1.2-1.fc21.x86_64 ncurses-libs-5.9-16.20140323.fc21.x86_64 nss-softokn-freebl-3.21.0-1.1.fc21.x86_64 pcre-8.35-17.fc21.x86_64 readline-6.3-5.fc21.x86_64 systemd-libs-216-25.fc21.x86_64 xz-libs-5.1.2-14alpha.fc21.x86_64 zlib-1.2.8-7.fc21.x86_64 (gdb) bt #0 0x00007ffff632db28 in pthread_once () from /lib64/libpthread.so.0 #1 0x00007ffff5bf17ac in backtrace () from /lib64/libc.so.6 #2 0x00007ffff5b02aa9 in backtrace_and_maps () from /lib64/libc.so.6 #3 0x00007ffff5b5ad9e in __libc_message () from /lib64/libc.so.6 #4 0x00007ffff5b63acf in _int_malloc () from /lib64/libc.so.6 #5 0x00007ffff5b6615e in malloc () from /lib64/libc.so.6 #6 0x00007ffff7de90a5 in _dl_map_object_deps () from /lib64/ld-linux-x86-64.so.2 #7 0x00007ffff7def6f6 in dl_open_worker () from /lib64/ld-linux-x86-64.so.2 #8 0x00007ffff7deadd4 in _dl_catch_error () from /lib64/ld-linux-x86-64.so.2 #9 0x00007ffff7deeec3 in _dl_open () from /lib64/ld-linux-x86-64.so.2 #10 0x00007ffff5c1e33d in do_dlopen () from /lib64/libc.so.6 #11 0x00007ffff7deadd4 in _dl_catch_error () from /lib64/ld-linux-x86-64.so.2 #12 0x00007ffff5c1e3f4 in __libc_dlopen_mode () from /lib64/libc.so.6 #13 0x00007ffff5bf1695 in init () from /lib64/libc.so.6 #14 0x00007ffff632db30 in pthread_once () from /lib64/libpthread.so.0 #15 0x00007ffff5bf17ac in backtrace () from /lib64/libc.so.6 #16 0x00007ffff5b02aa9 in backtrace_and_maps () from /lib64/libc.so.6 #17 0x00007ffff5b5ad9e in __libc_message () from /lib64/libc.so.6 #18 0x00007ffff5b63acf in _int_malloc () from /lib64/libc.so.6 #19 0x00007ffff5b6615e in malloc () from /lib64/libc.so.6 #20 0x00007ffff6de61db in _talloc_array () from /lib64/libtalloc.so.2 #21 0x00007ffff7983141 in value_data_aprints (ctx=0x96c660, type=PW_TYPE_ABINARY, enumv=0x0, data=0x96c660, inlen=50, quote=39 '\'') at src/lib/value.c:1518 #22 0x00007ffff7bc5942 in xlat_debug_attr (instance=0x0, request=0x969900, fmt=0x970540 "request:", out=0x96bdf0 "", outlen=2048) at src/main/xlat.c:477 #23 0x00007ffff7bc9e4d in xlat_aprint (ctx=0x969900, request=0x969900, node=0x95c4e0, escape=0x0, escape_ctx=0x0, lvl=0) at src/main/xlat.c:2306 #24 0x00007ffff7bca0e2 in xlat_process (out=0x7fffffffc130, request=0x969900, head=0x95c4e0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2398 #25 0x00007ffff7bca3f1 in xlat_expand_struct (out=0x7fffffffc268, outlen=0, request=0x969900, node=0x95c4e0, escape=0x0, escape_ctx=0x0) at src/main/xlat.c:2470 #26 0x00007ffff7bca8f6 in radius_axlat_struct (out=0x7fffffffc268, request=0x969900, xlat=0x95c4e0, escape=0x0, ---Type to continue, or q to quit--- ctx=0x0) at src/main/xlat.c:2611 #27 0x00007ffff7bbd6d9 in tmpl_aexpand (ctx=0x969900, out=0x7fffffffc268, request=0x969900, vpt=0x8d2260, escape=0x0, escape_ctx=0x0) at src/main/tmpl.c:1514 #28 0x00007ffff7baf388 in radius_evaluate_map (request=0x969900, modreturn=10, depth=0, c=0x8d2130) at src/main/evaluate.c:684 #29 0x00007ffff7baf4ea in radius_evaluate_cond (request=0x969900, modreturn=10, depth=0, c=0x8d2130) at src/main/evaluate.c:746 #30 0x0000000000429390 in modcall_recurse (request=0x969900, component=MOD_POST_AUTH, depth=3, entry=0x7fffffffdb68, do_next_sibling=true) at src/main/modcall.c:483 #31 0x0000000000429146 in modcall_child (request=0x969900, component=MOD_POST_AUTH, depth=3, entry=0x7fffffffdb50, c=0x952370, result=0x7fffffffcdd4, do_next_sibling=true) at src/main/modcall.c:408 #32 0x000000000042a082 in modcall_recurse (request=0x969900, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdb50, do_next_sibling=true) at src/main/modcall.c:789 #33 0x0000000000429146 in modcall_child (request=0x969900, component=MOD_POST_AUTH, depth=2, entry=0x7fffffffdb38, c=0x951fb0, result=0x7fffffffd3f4, do_next_sibling=true) at src/main/modcall.c:408 #34 0x000000000042a082 in modcall_recurse (request=0x969900, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb38, do_next_sibling=true) at src/main/modcall.c:789 #35 0x0000000000429146 in modcall_child (request=0x969900, component=MOD_POST_AUTH, depth=1, entry=0x7fffffffdb20, c=0x951eb0, result=0x7fffffffda14, do_next_sibling=true) at src/main/modcall.c:408 #36 0x000000000042a082 in modcall_recurse (request=0x969900, component=MOD_POST_AUTH, depth=0, entry=0x7fffffffdb20, do_next_sibling=true) at src/main/modcall.c:789 #37 0x000000000042ad99 in modcall (component=MOD_POST_AUTH, c=0x951db0, request=0x969900) at src/main/modcall.c:1134 #38 0x00000000004265ba in indexed_modcall (comp=MOD_POST_AUTH, idx=0, request=0x969900) at src/main/modules.c:1028 #39 0x00000000004289bb in process_post_auth (postauth_type=0, request=0x969900) at src/main/modules.c:2241 #40 0x000000000040fa72 in rad_postauth (request=0x969900) at src/main/auth.c:317 #41 0x000000000043d360 in request_finish (request=0x969900, action=1) at src/main/process.c:1334 #42 0x000000000043db1a in request_running (request=0x969900, action=1) at src/main/process.c:1570 #43 0x000000000043c802 in request_queue_or_run (request=0x969900, process=0x43d949 ) at src/main/process.c:1025 #44 0x000000000043e34d in request_receive (ctx=0x9696b0, listener=0x9674e0, packet=0x969710, client=0x887bc0, fun=0x40fd49 ) at src/main/process.c:1798 #45 0x00000000004186ce in auth_socket_recv (listener=0x9674e0) at src/main/listen.c:1571 ---Type to continue, or q to quit--- #46 0x00000000004452c8 in event_socket_handler (xel=0x8f70f0, fd=8, ctx=0x9674e0) at src/main/process.c:4611 #47 0x00007ffff7986b8f in fr_event_loop (el=0x8f70f0) at src/lib/event.c:649 #48 0x00000000004470af in radius_event_process () at src/main/process.c:5686 #49 0x0000000000431375 in main (argc=2, argv=0x7fffffffe5b8) at src/main/radiusd.c:589 (gdb) (gdb)