Proxy (check status of the 3rd party server)

Peter Balsianok balsianok.peter at gmail.com
Mon Aug 17 09:48:04 CEST 2015


Thank you for your advise Alan.

I have changed DEFAULT configuration, but the problem is persisting :(.

Debug output:
[radiusd at tdrad1 acct-test-orig]$ ./run-debug.sh
Mon Aug 17 09:43:09 2015 : Debug: Server was built with:
Mon Aug 17 09:43:09 2015 : Debug:   accounting               : yes
Mon Aug 17 09:43:09 2015 : Debug:   authentication           : yes
Mon Aug 17 09:43:09 2015 : Debug:   ascend-binary-attributes : yes
Mon Aug 17 09:43:09 2015 : Debug:   coa                      : yes
Mon Aug 17 09:43:09 2015 : Debug:   control-socket           : yes
Mon Aug 17 09:43:09 2015 : Debug:   detail                   : yes
Mon Aug 17 09:43:09 2015 : Debug:   dhcp                     : yes
Mon Aug 17 09:43:09 2015 : Debug:   dynamic-clients          : yes
Mon Aug 17 09:43:09 2015 : Debug:   osfc2                    : no
Mon Aug 17 09:43:09 2015 : Debug:   proxy                    : yes
Mon Aug 17 09:43:09 2015 : Debug:   regex-pcre               : no
Mon Aug 17 09:43:09 2015 : Debug:   regex-posix              : yes
Mon Aug 17 09:43:09 2015 : Debug:   regex-posix-extended     : yes
Mon Aug 17 09:43:09 2015 : Debug:   session-management       : yes
Mon Aug 17 09:43:09 2015 : Debug:   stats                    : yes
Mon Aug 17 09:43:09 2015 : Debug:   tcp                      : yes
Mon Aug 17 09:43:09 2015 : Debug:   threads                  : yes
Mon Aug 17 09:43:09 2015 : Debug:   tls                      : yes
Mon Aug 17 09:43:09 2015 : Debug:   unlang                   : yes
Mon Aug 17 09:43:09 2015 : Debug:   vmps                     : yes
Mon Aug 17 09:43:09 2015 : Debug:   developer                : yes
Mon Aug 17 09:43:09 2015 : Debug: Server core libs:
Mon Aug 17 09:43:09 2015 : Debug:   freeradius-server        : 3.0.10
Mon Aug 17 09:43:09 2015 : Debug:   talloc                   : 2.0.*
Mon Aug 17 09:43:09 2015 : Debug:   ssl                      : 0.9.8b
release
Mon Aug 17 09:43:09 2015 : Debug: Endianess:
Mon Aug 17 09:43:09 2015 : Debug:   little
Mon Aug 17 09:43:09 2015 : Debug: Compilation flags:
Mon Aug 17 09:43:09 2015 : Info: Copyright (C) 1999-2015 The FreeRADIUS
server project and contributors
Mon Aug 17 09:43:09 2015 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Mon Aug 17 09:43:09 2015 : Info: PARTICULAR PURPOSE
Mon Aug 17 09:43:09 2015 : Info: You may redistribute copies of FreeRADIUS
under the terms of the
Mon Aug 17 09:43:09 2015 : Info: GNU General Public License
Mon Aug 17 09:43:09 2015 : Info: For more information about these matters,
see the file named COPYRIGHT
Mon Aug 17 09:43:09 2015 : Info: Starting - reading configuration files ...
Mon Aug 17 09:43:09 2015 : Debug: including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary
Mon Aug 17 09:43:09 2015 : Debug: including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary.dhcp
Mon Aug 17 09:43:09 2015 : Debug: including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary.vqp
Mon Aug 17 09:43:09 2015 : Debug: including dictionary file
/app/radius/conf/acct-test-orig/dictionary
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/radiusd.conf
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/templates.conf
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/proxy.conf
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/clients.conf
Mon Aug 17 09:43:09 2015 : Debug: including files in directory
/app/radius/conf/acct-test-orig/mods-enabled/
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/files
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/expr
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/preprocess
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/chap
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/perl
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/mods-enabled/pap
Mon Aug 17 09:43:09 2015 : Debug: including files in directory
/app/radius/conf/acct-test-orig/policy.d/
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/abfab-tr
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/debug
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/control
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/eap
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/canonicalization
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/dhcp
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/accounting
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/cui
Mon Aug 17 09:43:09 2015 : Debug: OPTIMIZING
(${policy.cui_require_operator_name} == yes) --> FALSE
Mon Aug 17 09:43:09 2015 : Debug: OPTIMIZING (no == yes) --> FALSE
Mon Aug 17 09:43:09 2015 : Debug: OPTIMIZING
(${policy.cui_require_operator_name} == yes) --> FALSE
Mon Aug 17 09:43:09 2015 : Debug: OPTIMIZING (no == yes) --> FALSE
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/operator-name
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/policy.d/filter
Mon Aug 17 09:43:09 2015 : Debug: including files in directory
/app/radius/conf/acct-test-orig/sites-enabled/
Mon Aug 17 09:43:09 2015 : Debug: including configuration file
/app/radius/conf/acct-test-orig/sites-enabled/default
Mon Aug 17 09:43:09 2015 : Debug: main {
Mon Aug 17 09:43:09 2015 : Debug: name = "acct-test-orig"
Mon Aug 17 09:43:09 2015 : Debug: prefix = "/app/radius/freeradius-3.0.9"
Mon Aug 17 09:43:09 2015 : Debug: localstatedir =
"/app_log/radius/acct-test-orig/"
Mon Aug 17 09:43:09 2015 : Debug: sbindir =
"/app/radius/freeradius-3.0.9/sbin"
Mon Aug 17 09:43:09 2015 : Debug: logdir = "/app_log/radius/acct-test-orig/"
Mon Aug 17 09:43:09 2015 : Debug: run_dir =
"/app_log/radius/acct-test-orig/"
Mon Aug 17 09:43:09 2015 : Debug: libdir =
"/app/radius/freeradius-3.0.9/lib"
Mon Aug 17 09:43:09 2015 : Debug: radacctdir =
"/app_log/radius/acct-test-orig//radacct"
Mon Aug 17 09:43:09 2015 : Debug: panic_action = "gdb -silent -x
/app/radius/freeradius-3.0.9/../raddb/acct-test-orig/panic.gdb %e %p 2>&1 |
tee /app_log/radius/acct-test-orig//gdb-acct-test-orig-%p.log"
Mon Aug 17 09:43:09 2015 : Debug: hostname_lookups = no
Mon Aug 17 09:43:09 2015 : Debug: max_request_time = 5
Mon Aug 17 09:43:09 2015 : Debug: cleanup_delay = 2
Mon Aug 17 09:43:09 2015 : Debug: max_requests = 25600
Mon Aug 17 09:43:09 2015 : Debug: pidfile =
"/app_log/radius/acct-test-orig//radius.pid"
Mon Aug 17 09:43:09 2015 : Debug: checkrad =
"/app/radius/freeradius-3.0.9/sbin/checkrad"
Mon Aug 17 09:43:09 2015 : Debug: debug_level = 0
Mon Aug 17 09:43:09 2015 : Debug: proxy_requests = yes
Mon Aug 17 09:43:09 2015 : Debug:  log {
Mon Aug 17 09:43:09 2015 : Debug:   stripped_names = no
Mon Aug 17 09:43:09 2015 : Debug:   auth = no
Mon Aug 17 09:43:09 2015 : Debug:   auth_badpass = no
Mon Aug 17 09:43:09 2015 : Debug:   auth_goodpass = no
Mon Aug 17 09:43:09 2015 : Debug:   colourise = yes
Mon Aug 17 09:43:09 2015 : Debug:   msg_denied = "You are already logged in
- access denied"
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[272]: The item 'destination'
is defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[289]: The item 'file' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[335]: The item
'syslog_facility' is defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  resources {
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  security {
Mon Aug 17 09:43:09 2015 : Debug:   max_attributes = 200
Mon Aug 17 09:43:09 2015 : Debug:   reject_delay = 0.000000
Mon Aug 17 09:43:09 2015 : Debug:   status_server = yes
Mon Aug 17 09:43:09 2015 : Debug:   allow_vulnerable_openssl = "yes"
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[451]: The item
'allow_core_dumps' is defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[67]: The item 'confdir' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[69]: The item 'certdir' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[70]: The item 'cadir' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[72]: The item 'loader_dir' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[74]: The item
'notification_dir' is defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[78]: The item 'db_dir' is
defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Warning:
/app/radius/conf/acct-test-orig/radiusd.conf[144]: The item
'correct_escapes' is defined, but is unused by the configuration
Mon Aug 17 09:43:09 2015 : Debug: }
Mon Aug 17 09:43:09 2015 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Mon Aug 17 09:43:09 2015 : Debug:  proxy server {
Mon Aug 17 09:43:09 2015 : Debug:   retry_delay = 5
Mon Aug 17 09:43:09 2015 : Debug:   retry_count = 3
Mon Aug 17 09:43:09 2015 : Debug:   default_fallback = no
Mon Aug 17 09:43:09 2015 : Debug:   dead_time = 120
Mon Aug 17 09:43:09 2015 : Debug:   wake_all_if_all_dead = no
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  home_server localhostA {
Mon Aug 17 09:43:09 2015 : Debug:   ipaddr = 127.0.0.1
Mon Aug 17 09:43:09 2015 : Debug:   port = 60813
Mon Aug 17 09:43:09 2015 : Debug:   type = "acct"
Mon Aug 17 09:43:09 2015 : Debug:   secret = "test123test"
Mon Aug 17 09:43:09 2015 : Debug:   response_window = 20.000000
Mon Aug 17 09:43:09 2015 : Debug:   response_timeouts = 1
Mon Aug 17 09:43:09 2015 : Debug:   max_outstanding = 65536
Mon Aug 17 09:43:09 2015 : Debug:   zombie_period = 40
Mon Aug 17 09:43:09 2015 : Debug:   status_check = "status-server"
Mon Aug 17 09:43:09 2015 : Debug:   ping_interval = 30
Mon Aug 17 09:43:09 2015 : Debug:   check_interval = 30
Mon Aug 17 09:43:09 2015 : Debug:   check_timeout = 4
Mon Aug 17 09:43:09 2015 : Debug:   num_answers_to_alive = 3
Mon Aug 17 09:43:09 2015 : Debug:   revive_interval = 120
Mon Aug 17 09:43:09 2015 : Debug:   limit {
Mon Aug 17 09:43:09 2015 : Debug:   max_connections = 16
Mon Aug 17 09:43:09 2015 : Debug:   max_requests = 0
Mon Aug 17 09:43:09 2015 : Debug:   lifetime = 0
Mon Aug 17 09:43:09 2015 : Debug:   idle_timeout = 0
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   coa {
Mon Aug 17 09:43:09 2015 : Debug:   irt = 2
Mon Aug 17 09:43:09 2015 : Debug:   mrt = 16
Mon Aug 17 09:43:09 2015 : Debug:   mrc = 5
Mon Aug 17 09:43:09 2015 : Debug:   mrd = 30
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Warning: WARNING: Ignoring "response_window =
20.000000", forcing to "response_window = 5.000000"
Mon Aug 17 09:43:09 2015 : Debug:  home_server_pool my_acct_failover {
Mon Aug 17 09:43:09 2015 : Debug: type = fail-over
Mon Aug 17 09:43:09 2015 : Debug: home_server = localhostA
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  realm testproxy.sk {
Mon Aug 17 09:43:09 2015 : Debug: acct_pool = my_acct_failover
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  realm LOCAL {
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug: radiusd: #### Loading Clients ####
Mon Aug 17 09:43:09 2015 : Debug:  client localhost {
Mon Aug 17 09:43:09 2015 : Debug:   ipaddr = 127.0.0.1
Mon Aug 17 09:43:09 2015 : Debug:   require_message_authenticator = no
Mon Aug 17 09:43:09 2015 : Debug:   secret = "test123test"
Mon Aug 17 09:43:09 2015 : Debug:   nas_type = "other"
Mon Aug 17 09:43:09 2015 : Debug:   proto = "*"
Mon Aug 17 09:43:09 2015 : Debug:   limit {
Mon Aug 17 09:43:09 2015 : Debug:   max_connections = 16
Mon Aug 17 09:43:09 2015 : Debug:   lifetime = 0
Mon Aug 17 09:43:09 2015 : Debug:   idle_timeout = 30
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to
prefix tree 32
Mon Aug 17 09:43:09 2015 : Debug:  client localhost_ipv6 {
Mon Aug 17 09:43:09 2015 : Debug:   ipv6addr = ::1
Mon Aug 17 09:43:09 2015 : Debug:   require_message_authenticator = no
Mon Aug 17 09:43:09 2015 : Debug:   secret = "testing123"
Mon Aug 17 09:43:09 2015 : Debug:   limit {
Mon Aug 17 09:43:09 2015 : Debug:   max_connections = 16
Mon Aug 17 09:43:09 2015 : Debug:   lifetime = 0
Mon Aug 17 09:43:09 2015 : Debug:   idle_timeout = 30
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug: Adding client ::1/128 (::1) to prefix
tree 128
Mon Aug 17 09:43:09 2015 : Info: Debugger not attached
Mon Aug 17 09:43:09 2015 : Debug: radiusd: #### Instantiating modules ####
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_files.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_files, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_files
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "files" from file
/app/radius/conf/acct-test-orig/mods-enabled/files
Mon Aug 17 09:43:09 2015 : Debug:   files {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/files/authorize"
Mon Aug 17 09:43:09 2015 : Debug:   acctusersfile =
"/app/radius/conf/acct-test-orig/mods-config/files/accounting"
Mon Aug 17 09:43:09 2015 : Debug:   preproxy_usersfile =
"/app/radius/conf/acct-test-orig/mods-config/files/pre-proxy"
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_expr.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_expr, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_expr
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "expr" from file
/app/radius/conf/acct-test-orig/mods-enabled/expr
Mon Aug 17 09:43:09 2015 : Debug:   expr {
Mon Aug 17 09:43:09 2015 : Debug:   safe_characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_:
/äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_preprocess.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_preprocess, checking if it's
valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_preprocess
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "preprocess" from file
/app/radius/conf/acct-test-orig/mods-enabled/preprocess
Mon Aug 17 09:43:09 2015 : Debug:   preprocess {
Mon Aug 17 09:43:09 2015 : Debug:   huntgroups =
"/app/radius/conf/acct-test-orig/mods-config/preprocess/huntgroups"
Mon Aug 17 09:43:09 2015 : Debug:   hints =
"/app/radius/conf/acct-test-orig/mods-config/preprocess/hints"
Mon Aug 17 09:43:09 2015 : Debug:   with_ascend_hack = no
Mon Aug 17 09:43:09 2015 : Debug:   ascend_channels_per_line = 23
Mon Aug 17 09:43:09 2015 : Debug:   with_ntdomain_hack = no
Mon Aug 17 09:43:09 2015 : Debug:   with_specialix_jetstream_hack = no
Mon Aug 17 09:43:09 2015 : Debug:   with_cisco_vsa_hack = no
Mon Aug 17 09:43:09 2015 : Debug:   with_alvarion_vsa_hack = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_chap.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_chap, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_chap
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "chap" from file
/app/radius/conf/acct-test-orig/mods-enabled/chap
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_attr_filter.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_attr_filter, checking if it's
valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module
"attr_filter.post-proxy" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter attr_filter.post-proxy {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/attr_filter/post-proxy"
Mon Aug 17 09:43:09 2015 : Debug:   key = "%{Realm}"
Mon Aug 17 09:43:09 2015 : Debug:   relaxed = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module
"attr_filter.pre-proxy" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter attr_filter.pre-proxy {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/attr_filter/pre-proxy"
Mon Aug 17 09:43:09 2015 : Debug:   key = "%{Realm}"
Mon Aug 17 09:43:09 2015 : Debug:   relaxed = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module
"attr_filter.access_reject" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter attr_filter.access_reject {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/attr_filter/access_reject"
Mon Aug 17 09:43:09 2015 : Debug:   key = "%{User-Name}"
Mon Aug 17 09:43:09 2015 : Debug:   relaxed = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module
"attr_filter.access_challenge" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter
attr_filter.access_challenge {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/attr_filter/access_challenge"
Mon Aug 17 09:43:09 2015 : Debug:   key = "%{User-Name}"
Mon Aug 17 09:43:09 2015 : Debug:   relaxed = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module
"attr_filter.accounting_response" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter
attr_filter.accounting_response {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/attr_filter/accounting_response"
Mon Aug 17 09:43:09 2015 : Debug:   key = "%{User-Name}"
Mon Aug 17 09:43:09 2015 : Debug:   relaxed = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_always.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_always, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_always
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "reject" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always reject {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "reject"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "fail" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always fail {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "fail"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "ok" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always ok {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "ok"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "handled" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always handled {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "handled"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "invalid" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always invalid {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "invalid"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "userlock" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always userlock {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "userlock"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "notfound" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always notfound {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "notfound"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "noop" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always noop {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "noop"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "updated" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   always updated {
Mon Aug 17 09:43:09 2015 : Debug:   rcode = "updated"
Mon Aug 17 09:43:09 2015 : Debug:   simulcount = 0
Mon Aug 17 09:43:09 2015 : Debug:   mpp = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_perl.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_perl, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_perl
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "perl" from file
/app/radius/conf/acct-test-orig/mods-enabled/perl
Mon Aug 17 09:43:09 2015 : Debug:   perl {
Mon Aug 17 09:43:09 2015 : Debug:   filename =
"/app/radius/conf/acct-test-orig/mods-config/perl/example.pl"
Mon Aug 17 09:43:09 2015 : Debug:   func_authorize = "authorize"
Mon Aug 17 09:43:09 2015 : Debug:   func_authenticate = "authenticate"
Mon Aug 17 09:43:09 2015 : Debug:   func_post_auth = "post_auth"
Mon Aug 17 09:43:09 2015 : Debug:   func_accounting = "accounting"
Mon Aug 17 09:43:09 2015 : Debug:   func_preacct = "preacct"
Mon Aug 17 09:43:09 2015 : Debug:   func_checksimul = "checksimul"
Mon Aug 17 09:43:09 2015 : Debug:   func_detach = "detach"
Mon Aug 17 09:43:09 2015 : Debug:   func_xlat = "xlat"
Mon Aug 17 09:43:09 2015 : Debug:   func_pre_proxy = "pre_proxy"
Mon Aug 17 09:43:09 2015 : Debug:   func_post_proxy = "post_proxy"
Mon Aug 17 09:43:09 2015 : Debug:   func_recv_coa = "recv_coa"
Mon Aug 17 09:43:09 2015 : Debug:   func_send_coa = "send_coa"
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_realm.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_realm, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_realm
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "IPASS" from file
/app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   realm IPASS {
Mon Aug 17 09:43:09 2015 : Debug:   format = "prefix"
Mon Aug 17 09:43:09 2015 : Debug:   delimiter = "/"
Mon Aug 17 09:43:09 2015 : Debug:   ignore_default = no
Mon Aug 17 09:43:09 2015 : Debug:   ignore_null = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "suffix" from file
/app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   realm suffix {
Mon Aug 17 09:43:09 2015 : Debug:   format = "suffix"
Mon Aug 17 09:43:09 2015 : Debug:   delimiter = "@"
Mon Aug 17 09:43:09 2015 : Debug:   ignore_default = no
Mon Aug 17 09:43:09 2015 : Debug:   ignore_null = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "realmpercent" from
file /app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   realm realmpercent {
Mon Aug 17 09:43:09 2015 : Debug:   format = "suffix"
Mon Aug 17 09:43:09 2015 : Debug:   delimiter = "%"
Mon Aug 17 09:43:09 2015 : Debug:   ignore_default = no
Mon Aug 17 09:43:09 2015 : Debug:   ignore_null = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "ntdomain" from file
/app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   realm ntdomain {
Mon Aug 17 09:43:09 2015 : Debug:   format = "prefix"
Mon Aug 17 09:43:09 2015 : Debug:   delimiter = "\\"
Mon Aug 17 09:43:09 2015 : Debug:   ignore_default = no
Mon Aug 17 09:43:09 2015 : Debug:   ignore_null = no
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/rlm_pap.so"
Mon Aug 17 09:43:09 2015 : Debug: Loaded rlm_pap, checking if it's valid
Mon Aug 17 09:43:09 2015 : Debug:   # Loaded module rlm_pap
Mon Aug 17 09:43:09 2015 : Debug:   # Loading module "pap" from file
/app/radius/conf/acct-test-orig/mods-enabled/pap
Mon Aug 17 09:43:09 2015 : Debug:   pap {
Mon Aug 17 09:43:09 2015 : Debug:   normalise = yes
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  instantiate {
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "perl" from file
/app/radius/conf/acct-test-orig/mods-enabled/perl
Mon Aug 17 09:43:09 2015 : Debug:  }
Mon Aug 17 09:43:09 2015 : Debug:  modules {
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "files" from
file /app/radius/conf/acct-test-orig/mods-enabled/files
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/files/authorize
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/files/accounting
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/files/pre-proxy
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "preprocess"
from file /app/radius/conf/acct-test-orig/mods-enabled/preprocess
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/preprocess/huntgroups
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/preprocess/hints
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module
"attr_filter.post-proxy" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/attr_filter/post-proxy
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module
"attr_filter.pre-proxy" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/attr_filter/pre-proxy
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module
"attr_filter.access_reject" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/attr_filter/access_reject
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module
"attr_filter.access_challenge" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/attr_filter/access_challenge
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module
"attr_filter.accounting_response" from file
/app/radius/conf/acct-test-orig/mods-enabled/attr_filter
Mon Aug 17 09:43:09 2015 : Debug: reading pairlist file
/app/radius/conf/acct-test-orig/mods-config/attr_filter/accounting_response
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "reject" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "fail" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "ok" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "handled" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "invalid" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "userlock" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "notfound" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "noop" from file
/app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "updated" from
file /app/radius/conf/acct-test-orig/mods-enabled/always
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "IPASS" from
file /app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "suffix" from
file /app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "realmpercent"
from file /app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "ntdomain" from
file /app/radius/conf/acct-test-orig/mods-enabled/realm
Mon Aug 17 09:43:09 2015 : Debug:   # Instantiating module "pap" from file
/app/radius/conf/acct-test-orig/mods-enabled/pap
Mon Aug 17 09:43:09 2015 : Debug:  } # modules
Mon Aug 17 09:43:09 2015 : Debug: radiusd: #### Loading Virtual Servers ####
Mon Aug 17 09:43:09 2015 : Debug: server { # from file
/app/radius/conf/acct-test-orig/radiusd.conf
Mon Aug 17 09:43:09 2015 : Debug: } # server
Mon Aug 17 09:43:09 2015 : Debug: server default { # from file
/app/radius/conf/acct-test-orig/sites-enabled/default
Mon Aug 17 09:43:09 2015 : Debug:  authenticate {
Mon Aug 17 09:43:09 2015 : Debug:   group {
Mon Aug 17 09:43:09 2015 : Debug:    pap
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   group {
Mon Aug 17 09:43:09 2015 : Debug:    chap
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  } # authenticate
Mon Aug 17 09:43:09 2015 : Debug:  authorize {
Mon Aug 17 09:43:09 2015 : Debug:   policy filter_username {
Mon Aug 17 09:43:09 2015 : Debug:    if (!&User-Name) {
Mon Aug 17 09:43:09 2015 : Debug:     noop
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ / /) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Username contains whitespace'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ /@.*@/) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Multiple @ in username'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ /\.\./) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Username contains ..s'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ /@/ && !&User-Name
=~ /@(.+)\.(.+)$/) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Realm does not have at least one dot separator'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ /\.$/) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Realm ends with a dot'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    if (&User-Name =~ /@\./) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &reply:Reply-Message += 'Rejected:
Realm begins with a dot'
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:     reject
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   preprocess
Mon Aug 17 09:43:09 2015 : Debug:   chap
Mon Aug 17 09:43:09 2015 : Debug:   suffix
Mon Aug 17 09:43:09 2015 : Debug:   files
Mon Aug 17 09:43:09 2015 : Warning: Ignoring "sql" (see
raddb/mods-available/README.rst)
Mon Aug 17 09:43:09 2015 : Warning: Ignoring "ldap" (see
raddb/mods-available/README.rst)
Mon Aug 17 09:43:09 2015 : Debug:   pap
Mon Aug 17 09:43:09 2015 : Debug:  } # authorize
Mon Aug 17 09:43:09 2015 : Debug:  preacct {
Mon Aug 17 09:43:09 2015 : Debug:   preprocess
Mon Aug 17 09:43:09 2015 : Debug:   policy acct_unique {
Mon Aug 17 09:43:09 2015 : Debug:    if ("%{string:Class}" =~
/ai:([0-9a-f]{32})/) {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &Acct-Unique-Session-Id :=
"%{md5:%{1},%{Acct-Session-ID}}"
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:    else {
Mon Aug 17 09:43:09 2015 : Debug:     update {
Mon Aug 17 09:43:09 2015 : Debug:      &Acct-Unique-Session-Id :=
"%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}"
Mon Aug 17 09:43:09 2015 : Debug:     }
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   suffix
Mon Aug 17 09:43:09 2015 : Debug:   files
Mon Aug 17 09:43:09 2015 : Debug:  } # preacct
Mon Aug 17 09:43:09 2015 : Debug:  accounting {
Mon Aug 17 09:43:09 2015 : Debug:   attr_filter.accounting_response
Mon Aug 17 09:43:09 2015 : Debug:  } # accounting
Mon Aug 17 09:43:09 2015 : Debug:  post-auth {
Mon Aug 17 09:43:09 2015 : Debug:   update {
Mon Aug 17 09:43:09 2015 : Debug:    &reply[*] += &session-state[*]
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:   group {
Mon Aug 17 09:43:09 2015 : Debug:    attr_filter.access_reject
Mon Aug 17 09:43:09 2015 : Debug:   }
Mon Aug 17 09:43:09 2015 : Debug:  } # post-auth
Mon Aug 17 09:43:09 2015 : Debug: } # server default
Mon Aug 17 09:43:09 2015 : Debug: Created signal pipe.  Read end FD 5,
write end FD 6
Mon Aug 17 09:43:09 2015 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Mon Aug 17 09:43:09 2015 : Debug: Loading library using absolute path
"/app/radius/freeradius-3.0.9/lib/proto_acct.so"
Mon Aug 17 09:43:09 2015 : Debug: Failed with error:
/app/radius/freeradius-3.0.9/lib/proto_acct.so: cannot open shared object
file: No such file or directory
Mon Aug 17 09:43:09 2015 : Debug: Library file not found
Mon Aug 17 09:43:09 2015 : Debug: Loading library using linker search
path(s)
Mon Aug 17 09:43:09 2015 : Debug: Defaults         : /lib:/usr/lib
Mon Aug 17 09:43:09 2015 : Debug: Failed with error: proto_acct.so: cannot
open shared object file: No such file or directory
Mon Aug 17 09:43:09 2015 : Debug: listen {
Mon Aug 17 09:43:09 2015 : Debug:   type = "acct"
Mon Aug 17 09:43:09 2015 : Debug:   ipaddr = *
Mon Aug 17 09:43:09 2015 : Debug:   port = 10813
Mon Aug 17 09:43:09 2015 : Debug:    limit {
Mon Aug 17 09:43:09 2015 : Debug:     max_connections = 16
Mon Aug 17 09:43:09 2015 : Debug:     lifetime = 0
Mon Aug 17 09:43:09 2015 : Debug:     idle_timeout = 30
Mon Aug 17 09:43:09 2015 : Debug:    }
Mon Aug 17 09:43:09 2015 : Debug: }
Mon Aug 17 09:43:09 2015 : Debug: Listening on acct address * port 10813
bound to server default
Mon Aug 17 09:43:09 2015 : Debug: Opening new proxy socket 'proxy address *
port 0'
Mon Aug 17 09:43:09 2015 : Debug: Listening on proxy address * port 34833
Mon Aug 17 09:43:09 2015 : Info: Ready to process requests
  Socket: 7
  Proto: 0
  Src IP: 127.0.0.1
    port: 43842
  Dst IP: 127.0.0.1
    port: 10813
  Code: 4
  Id: 94
  Length: 219
  Vector: ec9b6b7be6d6df3ec7718bfcbccce9cd
  Data: 01  1a  6d 6f 6e 2d 7a 64 72 6f 6a 65 31 40 74 65 73 74
70 72 6f 78 79 2e 73 6b
04  06  d5 97 d8 c9
20  17  67 67 73 6e 2d 30 31 2d 62 62 31 2e 6f 72 61 6e
67 65 2e 73 6b
3d  06  00 00 00 05
28  06  00 00 00 01
1e  0c  70 72 6f 78 79 2e 63 6f 72 70
1f  0e  34 32 31 39 30 35 30 36 36 30 30 31
2c  12  64 35 39 37 64 39 31 35 32 33 39 32 30 38 34 30
32  12  64 35 39 37 64 39 31 35 31 31 63 32 38 30 32 34
33  06  00 00 00 01
08  06  ac 17 44 0b
06  06  00 00 00 02
07  06  00 00 00 07
2d  06  00 00 00 01
e2  06  00 00 00 08
e0  0a  32 01 91 04 60 09 98 f8
e3  0c  3c 44 35 3e 3c 39 37 3e d9 15
e1  06  23 92 08 40
e4  06  d5 97 fc 18
Mon Aug 17 09:43:12 2015 : Debug: (0) Received Accounting-Request Id 94
from 127.0.0.1:43842 to 127.0.0.1:10813 length 219
Mon Aug 17 09:43:12 2015 : Debug: (0)   User-Name = "
mon-zdroje1 at testproxy.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-IP-Address = 213.151.216.201
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-Identifier = "
ggsn-01-bb1.orange.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-Port-Type = Virtual
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Status-Type = Start
Mon Aug 17 09:43:12 2015 : Debug: (0)   Called-Station-Id = "proxy.corp"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Calling-Station-Id = "421905066001"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Session-Id = "d597d91523920840"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Multi-Session-Id =
"d597d91511c28024"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Link-Count = 1
Mon Aug 17 09:43:12 2015 : Debug: (0)   Framed-IP-Address = 172.23.68.11
Mon Aug 17 09:43:12 2015 : Debug: (0)   Service-Type = Framed-User
Mon Aug 17 09:43:12 2015 : Debug: (0)   Framed-Protocol = GPRS-PDP-Context
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Authentic = RADIUS
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-PRI-Number-Type = 8
Mon Aug 17 09:43:12 2015 : Debug: (0)   Attr-224 = 0x32019104600998f8
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Dial-Number =
"<D5><97>\331\025"
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Metric = 596772928
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Route-IP = 3583507480
Mon Aug 17 09:43:12 2015 : Debug: (0) # Executing section preacct from file
/app/radius/conf/acct-test-orig/sites-enabled/default
Mon Aug 17 09:43:12 2015 : Debug: (0)   preacct {
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: calling
preprocess (rlm_preprocess) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     [preprocess] = ok
Mon Aug 17 09:43:12 2015 : Debug: (0)     policy acct_unique {
Mon Aug 17 09:43:12 2015 : Debug: (0)       if ("%{string:Class}" =~
/ai:([0-9a-f]{32})/i) {
Mon Aug 17 09:43:12 2015 : Debug: (0)       EXPAND TMPL XLAT STRUCT
Mon Aug 17 09:43:12 2015 : Debug: (0)       EXPAND %{string:Class}
Mon Aug 17 09:43:12 2015 : Debug: (0)          -->
Mon Aug 17 09:43:12 2015 : Debug: No matches
Mon Aug 17 09:43:12 2015 : Debug: (0)       if ("%{string:Class}" =~
/ai:([0-9a-f]{32})/i)  -> FALSE
Mon Aug 17 09:43:12 2015 : Debug: (0)       else {
Mon Aug 17 09:43:12 2015 : Debug: (0)         update request {
Mon Aug 17 09:43:12 2015 : Debug: (0)           EXPAND
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
Mon Aug 17 09:43:12 2015 : Debug: (0)              -->
772f7c0824d05fe594797a68d34c3161
Mon Aug 17 09:43:12 2015 : Debug: (0)           &Acct-Unique-Session-Id :=
772f7c0824d05fe594797a68d34c3161
Mon Aug 17 09:43:12 2015 : Debug: (0)         } # update request = noop
Mon Aug 17 09:43:12 2015 : Debug: (0)       } # else = noop
Mon Aug 17 09:43:12 2015 : Debug: (0)     } # policy acct_unique = noop
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: calling
suffix (rlm_realm) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Checking for suffix after "@"
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Looking up realm "testproxy.sk"
for User-Name = "mon-zdroje1 at testproxy.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Found realm "testproxy.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Adding Stripped-User-Name =
"mon-zdroje1"
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Adding Realm = "testproxy.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Proxying request from user
mon-zdroje1 to realm testproxy.sk
Mon Aug 17 09:43:12 2015 : Debug: (0) suffix: Preparing to proxy accounting
request to realm "testproxy.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: returned from
suffix (rlm_realm) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     [suffix] = updated
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: calling files
(rlm_files) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[preacct]: returned from
files (rlm_files) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     [files] = noop
Mon Aug 17 09:43:12 2015 : Debug: (0)   } # preacct = updated
Mon Aug 17 09:43:12 2015 : Debug: (0) # Executing section accounting from
file /app/radius/conf/acct-test-orig/sites-enabled/default
Mon Aug 17 09:43:12 2015 : Debug: (0)   accounting {
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[accounting]: calling
attr_filter.accounting_response (rlm_attr_filter) for request 0
Mon Aug 17 09:43:12 2015 : Debug: %{User-Name}
Mon Aug 17 09:43:12 2015 : Debug: Parsed xlat tree:
Mon Aug 17 09:43:12 2015 : Debug: attribute --> User-Name
Mon Aug 17 09:43:12 2015 : Debug: (0) attr_filter.accounting_response:
EXPAND %{User-Name}
Mon Aug 17 09:43:12 2015 : Debug: (0) attr_filter.accounting_response:
 --> mon-zdroje1 at testproxy.sk
Mon Aug 17 09:43:12 2015 : Debug: (0) attr_filter.accounting_response:
Matched entry DEFAULT at line 12
Mon Aug 17 09:43:12 2015 : Debug: (0)     modsingle[accounting]: returned
from attr_filter.accounting_response (rlm_attr_filter) for request 0
Mon Aug 17 09:43:12 2015 : Debug: (0)     [attr_filter.accounting_response]
= updated
Mon Aug 17 09:43:12 2015 : Debug: (0)   } # accounting = updated
Mon Aug 17 09:43:12 2015 : Debug: (0) Empty pre-proxy section.  Using
default return values.
Mon Aug 17 09:43:12 2015 : Debug: (0) proxy: Trying to allocate ID (0/2)
Mon Aug 17 09:43:12 2015 : Debug: (0) proxy: Trying to open a new listener
to the home server
Mon Aug 17 09:43:12 2015 : Debug: Opening new proxy socket 'proxy address *
port 0'
Mon Aug 17 09:43:12 2015 : Debug: Listening on proxy address * port 36571
Mon Aug 17 09:43:12 2015 : Debug: (0) proxy: Trying to allocate ID (1/2)
Mon Aug 17 09:43:12 2015 : Debug: (0) proxy: request is now in proxy hash
Mon Aug 17 09:43:12 2015 : Debug: (0) proxy: allocating destination
127.0.0.1 port 60813 - Id 178
Mon Aug 17 09:43:12 2015 : Debug: (0) Proxying request to home server
127.0.0.1 port 60813 timeout 5.000000
01 0d  6d 6f 6e 2d 7a 64 72 6f 6a 65 31
04 06  d5 97 d8 c9
20 17  67 67 73 6e 2d 30 31 2d 62 62 31 2e 6f 72 61 6e
67 65 2e 73 6b
3d 06  00 00 00 05
28 06  00 00 00 01
1e 0c  70 72 6f 78 79 2e 63 6f 72 70
1f 0e  34 32 31 39 30 35 30 36 36 30 30 31
2c 12  64 35 39 37 64 39 31 35 32 33 39 32 30 38 34 30
32 12  64 35 39 37 64 39 31 35 31 31 63 32 38 30 32 34
33 06  00 00 00 01
08 06  ac 17 44 0b
06 06  00 00 00 02
07 06  00 00 00 07
2d 06  00 00 00 01
e2 06  00 00 00 08
e0 0a  32 01 91 04 60 09 98 f8
e3 0c  3c 44 35 3e 3c 39 37 3e d9 15
e1 06  23 92 08 40
e4 06  d5 97 fc 18
37 06  55 d1 90 90
21 04  39 34
Mon Aug 17 09:43:12 2015 : Debug: (0) Sent Accounting-Request Id 178 from
0.0.0.0:36571 to 127.0.0.1:60813 length 216
Mon Aug 17 09:43:12 2015 : Debug: (0)   User-Name = "mon-zdroje1"
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-IP-Address = 213.151.216.201
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-Identifier = "
ggsn-01-bb1.orange.sk"
Mon Aug 17 09:43:12 2015 : Debug: (0)   NAS-Port-Type = Virtual
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Status-Type = Start
Mon Aug 17 09:43:12 2015 : Debug: (0)   Called-Station-Id = "proxy.corp"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Calling-Station-Id = "421905066001"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Session-Id = "d597d91523920840"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Multi-Session-Id =
"d597d91511c28024"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Link-Count = 1
Mon Aug 17 09:43:12 2015 : Debug: (0)   Framed-IP-Address = 172.23.68.11
Mon Aug 17 09:43:12 2015 : Debug: (0)   Service-Type = Framed-User
Mon Aug 17 09:43:12 2015 : Debug: (0)   Framed-Protocol = GPRS-PDP-Context
Mon Aug 17 09:43:12 2015 : Debug: (0)   Acct-Authentic = RADIUS
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-PRI-Number-Type = 8
Mon Aug 17 09:43:12 2015 : Debug: (0)   Attr-224 = 0x32019104600998f8
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Dial-Number =
"<D5><97>\331\025"
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Metric = 596772928
Mon Aug 17 09:43:12 2015 : Debug: (0)   X-Ascend-Route-IP = 3583507480
Mon Aug 17 09:43:12 2015 : Debug: (0)   Event-Timestamp = "Aug 17 2015
09:43:12 CEST"
Mon Aug 17 09:43:12 2015 : Debug: (0)   Proxy-State = 0x3934
  Socket: 9
  Proto: 17
  Src IP: 0.0.0.0
    port: 36571
  Dst IP: 127.0.0.1
    port: 60813
  Code: 4
  Id: 178
  Length: 216
  Vector: e74bb5b5237ba0490154d63d7a44838d
  Data: 01  0d  6d 6f 6e 2d 7a 64 72 6f 6a 65 31
04  06  d5 97 d8 c9
20  17  67 67 73 6e 2d 30 31 2d 62 62 31 2e 6f 72 61 6e
67 65 2e 73 6b
3d  06  00 00 00 05
28  06  00 00 00 01
1e  0c  70 72 6f 78 79 2e 63 6f 72 70
1f  0e  34 32 31 39 30 35 30 36 36 30 30 31
2c  12  64 35 39 37 64 39 31 35 32 33 39 32 30 38 34 30
32  12  64 35 39 37 64 39 31 35 31 31 63 32 38 30 32 34
33  06  00 00 00 01
08  06  ac 17 44 0b
06  06  00 00 00 02
07  06  00 00 00 07
2d  06  00 00 00 01
e2  06  00 00 00 08
e0  0a  32 01 91 04 60 09 98 f8
e3  0c  3c 44 35 3e 3c 39 37 3e d9 15
e1  06  23 92 08 40
e4  06  d5 97 fc 18
37  06  55 d1 90 90
21  04  39 34
Mon Aug 17 09:43:12 2015 : Debug: Waking up in 0.3 seconds.
Mon Aug 17 09:43:12 2015 : Debug: (0) Expecting proxy response no later
than 4.669935 seconds from now
Mon Aug 17 09:43:12 2015 : Debug: Waking up in 4.6 seconds.
Mon Aug 17 09:43:17 2015 : Debug: (0) No proxy response, giving up on
request and marking it done
Mon Aug 17 09:43:17 2015 : Proxy: Marking home server 127.0.0.1 port 60813
as zombie (it has not responded in 5.000000 seconds).
Mon Aug 17 09:43:17 2015 : Debug: (1) proxy: Trying to allocate ID (0/2)
Mon Aug 17 09:43:17 2015 : Debug: (1) proxy: request is now in proxy hash
Mon Aug 17 09:43:17 2015 : Debug: (1) proxy: allocating destination
127.0.0.1 port 60813 - Id 18
Mon Aug 17 09:43:17 2015 : Debug: PING: Waiting 4 seconds for response to
ping
Mon Aug 17 09:43:17 2015 : Debug: (1) Sent Status-Server Id 18 from
0.0.0.0:36571 to 127.0.0.1:60813 length 0
Mon Aug 17 09:43:17 2015 : Debug: (1)   Message-Authenticator := 0x00
Mon Aug 17 09:43:17 2015 : Debug: (1)   NAS-Identifier := "Status Check 0.
Are you alive?"
50 12 ...
20 20  53 74 61 74 75 73 20 43 68 65 63 6b 20 30 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
  Socket: 9
  Proto: 0
  Src IP: 0.0.0.0
    port: 36571
  Dst IP: 127.0.0.1
    port: 60813
  Code: 12
  Id: 18
  Length: 70
  Vector: b4d8e37ec22a79bbb564a512370cfe23
  Data: 50  12  f2 95 eb a2 33 84 d7 05 6c aa 0e fc d8 70 ce 4f
20  20  53 74 61 74 75 73 20 43 68 65 63 6b 20 30 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Mon Aug 17 09:43:17 2015 : Debug: PING: Next status packet in 30 seconds
Mon Aug 17 09:43:17 2015 : ERROR: (0) Failing proxied request for user
"mon-zdroje1", due to lack of any response from home server 127.0.0.1 port
60813
Mon Aug 17 09:43:17 2015 : Debug: (0) Clearing existing &reply: attributes
Mon Aug 17 09:43:17 2015 : Debug: (0) Found Post-Proxy-Type Fail-Accounting
Mon Aug 17 09:43:17 2015 : Debug: (0) proxy: request is no longer in proxy
hash
Mon Aug 17 09:43:17 2015 : Debug: (0) Post-Proxy-Type sub-section not
found.  Ignoring.
Mon Aug 17 09:43:17 2015 : Debug: (0) Not sending reply to client.
Mon Aug 17 09:43:17 2015 : Debug: (0) Finished request
Mon Aug 17 09:43:17 2015 : Debug: (0) <done>: Cleaning up request packet ID
94 with timestamp +3
Mon Aug 17 09:43:17 2015 : Debug: Waking up in 3.9 seconds.
Mon Aug 17 09:43:21 2015 : Error: No response to status check 1 ID 18 for
home server 127.0.0.1 port 60813
Mon Aug 17 09:43:21 2015 : Debug: (1) proxy: request is no longer in proxy
hash
Mon Aug 17 09:43:21 2015 : Debug: Waking up in 24.4 seconds.
Mon Aug 17 09:43:46 2015 : Debug: (2) proxy: Trying to allocate ID (0/2)
Mon Aug 17 09:43:46 2015 : Debug: (2) proxy: request is now in proxy hash
Mon Aug 17 09:43:46 2015 : Debug: (2) proxy: allocating destination
127.0.0.1 port 60813 - Id 14
Mon Aug 17 09:43:46 2015 : Debug: PING: Waiting 4 seconds for response to
ping
Mon Aug 17 09:43:46 2015 : Debug: (2) Sent Status-Server Id 14 from
0.0.0.0:36571 to 127.0.0.1:60813 length 0
Mon Aug 17 09:43:46 2015 : Debug: (2)   Message-Authenticator := 0x00
Mon Aug 17 09:43:46 2015 : Debug: (2)   NAS-Identifier := "Status Check 1.
Are you alive?"
50 12 ...
20 20  53 74 61 74 75 73 20 43 68 65 63 6b 20 31 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
  Socket: 9
  Proto: 0
  Src IP: 0.0.0.0
    port: 36571
  Dst IP: 127.0.0.1
    port: 60813
  Code: 12
  Id: 14
  Length: 70
  Vector: e05c638156153316b44d2765df2dc725
  Data: 50  12  46 03 4a 15 13 fb 56 93 22 9f c1 46 0c 18 66 cc
20  20  53 74 61 74 75 73 20 43 68 65 63 6b 20 31 2e 20
41 72 65 20 79 6f 75 20 61 6c 69 76 65 3f
Mon Aug 17 09:43:46 2015 : Debug: PING: Next status packet in 30 seconds
Mon Aug 17 09:43:46 2015 : Debug: Waking up in 3.9 seconds.
  Socket: 9
  Proto: 0
  Src IP: 127.0.0.1
    port: 60813
  Dst IP: 127.0.0.1
    port: 36571
  Code: 5
  Id: 14
  Length: 20
  Vector: c7c21077ac5bc7ab2bb6b2ca152354ed
Mon Aug 17 09:43:46 2015 : Proxy: No outstanding request was found for
Accounting-Response packet from host 127.0.0.1 port 60813 - ID 14
Mon Aug 17 09:43:46 2015 : Debug: Waking up in 3.9 seconds.
Mon Aug 17 09:43:50 2015 : Error: No response to status check 2 ID 14 for
home server 127.0.0.1 port 60813
Mon Aug 17 09:43:50 2015 : Debug: (2) proxy: request is no longer in proxy
hash
Mon Aug 17 09:43:50 2015 : Debug: Waking up in 27.7 seconds.



Debug output (3rd party instance):
[radiusd at tdrad1 proxy-test-A]$ ./run-debug.sh
Copyright (C) 1999-2015 The FreeRADIUS server project and contributors
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License
For more information about these matters, see the file named COPYRIGHT
Starting - reading configuration files ...
including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary
including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary.dhcp
including dictionary file
/app/radius/freeradius-3.0.9/share/freeradius/dictionary.vqp
including dictionary file /app/radius/conf/proxy-test-A/dictionary
including configuration file /app/radius/conf/proxy-test-A/radiusd.conf
including configuration file /app/radius/conf/proxy-test-A/templates.conf
including configuration file /app/radius/conf/proxy-test-A/proxy.conf
including configuration file /app/radius/conf/proxy-test-A/clients.conf
including files in directory /app/radius/conf/proxy-test-A/mods-enabled/
including configuration file
/app/radius/conf/proxy-test-A/mods-enabled/files
including configuration file /app/radius/conf/proxy-test-A/mods-enabled/expr
including configuration file
/app/radius/conf/proxy-test-A/mods-enabled/preprocess
including configuration file /app/radius/conf/proxy-test-A/mods-enabled/chap
including configuration file
/app/radius/conf/proxy-test-A/mods-enabled/always
including configuration file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
including configuration file
/app/radius/conf/proxy-test-A/mods-enabled/realm
including configuration file /app/radius/conf/proxy-test-A/mods-enabled/pap
including files in directory /app/radius/conf/proxy-test-A/policy-enabled/
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/debug
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/huntgroup
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/lns
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/username
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/nas
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/bdsl
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/SkyToll
including configuration file
/app/radius/conf/proxy-test-A/policy-enabled/filter
including files in directory /app/radius/conf/proxy-test-A/sites-enabled/
including configuration file
/app/radius/conf/proxy-test-A/sites-enabled/default
main {
name = "proxy-test-A"
prefix = "/app/radius/freeradius-3.0.9"
localstatedir = "/app_log/radius/proxy-test-A/"
sbindir = "/app/radius/freeradius-3.0.9/sbin"
logdir = "/app_log/radius/proxy-test-A/"
run_dir = "/app_log/radius/proxy-test-A/"
libdir = "/app/radius/freeradius-3.0.9/lib"
radacctdir = "/app_log/radius/proxy-test-A//radacct"
panic_action = "gdb -silent -x
/app/radius/freeradius-3.0.9/../raddb/proxy-test-A/panic.gdb %e %p 2>&1 |
tee /app_log/radius/proxy-test-A//gdb-proxy-test-A-%p.log"
hostname_lookups = no
max_request_time = 5
cleanup_delay = 2
max_requests = 25600
pidfile = "/app_log/radius/proxy-test-A//radius.pid"
checkrad = "/app/radius/freeradius-3.0.9/sbin/checkrad"
debug_level = 0
proxy_requests = yes
 log {
  stripped_names = no
  auth = no
  auth_badpass = no
  auth_goodpass = no
  colourise = yes
  msg_denied = "You are already logged in - access denied"
 }
 resources {
 }
 security {
  max_attributes = 200
  reject_delay = 0.000000
  status_server = yes
  allow_vulnerable_openssl = "yes"
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
  retry_delay = 5
  retry_count = 3
  default_fallback = no
  dead_time = 120
  wake_all_if_all_dead = no
 }
 realm LOCAL {
authhost = LOCAL
accthost = LOCAL
 }
 realm NULL {
authhost = LOCAL
accthost = LOCAL
 }
 realm DEFAULT {
authhost = LOCAL
accthost = LOCAL
 }
radiusd: #### Loading Clients ####
 client localhost {
  ipaddr = 127.0.0.1
  require_message_authenticator = no
  secret = <<< secret >>>
  nas_type = "other"
  proto = "*"
  limit {
  max_connections = 16
  lifetime = 0
  idle_timeout = 30
  }
 }
Debugger not attached
radiusd: #### Instantiating modules ####
  # Loaded module rlm_files
  # Loading module "files" from file
/app/radius/conf/proxy-test-A/mods-enabled/files
  files {
  filename = "/app/radius/conf/proxy-test-A/mods-config/files/authorize"
  usersfile = "/app/radius/conf/proxy-test-A/mods-config/files/authorize"
  acctusersfile =
"/app/radius/conf/proxy-test-A/mods-config/files/accounting"
  preproxy_usersfile =
"/app/radius/conf/proxy-test-A/mods-config/files/pre-proxy"
  }
  # Loaded module rlm_expr
  # Loading module "expr" from file
/app/radius/conf/proxy-test-A/mods-enabled/expr
  expr {
  safe_characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_:
/��������������������������������������a����������������������������������������"
  }
  # Loaded module rlm_preprocess
  # Loading module "preprocess" from file
/app/radius/conf/proxy-test-A/mods-enabled/preprocess
  preprocess {
  with_ascend_hack = no
  ascend_channels_per_line = 23
  with_ntdomain_hack = no
  with_specialix_jetstream_hack = no
  with_cisco_vsa_hack = no
  with_alvarion_vsa_hack = no
  }
  # Loaded module rlm_chap
  # Loading module "chap" from file
/app/radius/conf/proxy-test-A/mods-enabled/chap
  # Loaded module rlm_always
  # Loading module "reject" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always reject {
  rcode = "reject"
  simulcount = 0
  mpp = no
  }
  # Loading module "fail" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always fail {
  rcode = "fail"
  simulcount = 0
  mpp = no
  }
  # Loading module "ok" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always ok {
  rcode = "ok"
  simulcount = 0
  mpp = no
  }
  # Loading module "handled" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always handled {
  rcode = "handled"
  simulcount = 0
  mpp = no
  }
  # Loading module "invalid" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always invalid {
  rcode = "invalid"
  simulcount = 0
  mpp = no
  }
  # Loading module "userlock" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always userlock {
  rcode = "userlock"
  simulcount = 0
  mpp = no
  }
  # Loading module "notfound" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always notfound {
  rcode = "notfound"
  simulcount = 0
  mpp = no
  }
  # Loading module "noop" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always noop {
  rcode = "noop"
  simulcount = 0
  mpp = no
  }
  # Loading module "updated" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  always updated {
  rcode = "updated"
  simulcount = 0
  mpp = no
  }
  # Loaded module rlm_linelog
  # Loading module "linelog" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  linelog {
  filename = "/app_log/radius/proxy-test-A//linelog"
  escape_filenames = no
  syslog_severity = "info"
  permissions = 384
  format = "This is a log message for %{User-Name}"
  reference = "messages.%{%{Packet-Type}:-default}"
  }
  # Loading module "log_request" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  linelog log_request {
  filename = "/app_log/radius/proxy-test-A/radius.log"
  escape_filenames = no
  syslog_severity = "info"
  permissions = 384
  format = "%t : Info: REQUEST(%{User-Name}): %{pairs:request:}"
  }
  # Loading module "log_control" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  linelog log_control {
  filename = "/app_log/radius/proxy-test-A/radius.log"
  escape_filenames = no
  syslog_severity = "info"
  permissions = 384
  format = "%t : Info: CONTROL(%{User-Name}): %{pairs:control:}"
  }
  # Loading module "log_reply" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  linelog log_reply {
  filename = "/app_log/radius/proxy-test-A/radius.log"
  escape_filenames = no
  syslog_severity = "info"
  permissions = 384
  format = "%t : Info REPLY(%{User-Name}): %{pairs:reply:}"
  }
  # Loaded module rlm_realm
  # Loading module "suffix" from file
/app/radius/conf/proxy-test-A/mods-enabled/realm
  realm suffix {
  format = "suffix"
  delimiter = "@"
  ignore_default = no
  ignore_null = no
  }
  # Loaded module rlm_pap
  # Loading module "pap" from file
/app/radius/conf/proxy-test-A/mods-enabled/pap
  pap {
  normalise = yes
  }
 instantiate {
 }
 modules {
  # Instantiating module "files" from file
/app/radius/conf/proxy-test-A/mods-enabled/files
reading pairlist file
/app/radius/conf/proxy-test-A/mods-config/files/authorize
reading pairlist file
/app/radius/conf/proxy-test-A/mods-config/files/authorize
reading pairlist file
/app/radius/conf/proxy-test-A/mods-config/files/accounting
reading pairlist file
/app/radius/conf/proxy-test-A/mods-config/files/pre-proxy
  # Instantiating module "preprocess" from file
/app/radius/conf/proxy-test-A/mods-enabled/preprocess
  # Instantiating module "reject" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "fail" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "ok" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "handled" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "invalid" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "userlock" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "notfound" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "noop" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "updated" from file
/app/radius/conf/proxy-test-A/mods-enabled/always
  # Instantiating module "linelog" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  # Instantiating module "log_request" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  # Instantiating module "log_control" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  # Instantiating module "log_reply" from file
/app/radius/conf/proxy-test-A/mods-enabled/linelog
  # Instantiating module "suffix" from file
/app/radius/conf/proxy-test-A/mods-enabled/realm
  # Instantiating module "pap" from file
/app/radius/conf/proxy-test-A/mods-enabled/pap
 } # modules
radiusd: #### Loading Virtual Servers ####
server { # from file /app/radius/conf/proxy-test-A/radiusd.conf
} # server
server default { # from file
/app/radius/conf/proxy-test-A/sites-enabled/default
 # Loading authenticate {...}
 # Loading authorize {...}
 # Loading accounting {...}
} # server default
radiusd: #### Opening IP addresses and Ports ####
listen {
  type = "auth"
  ipv4addr = localhost IPv4 address [127.0.0.1]
  port = 60812
}
listen {
  type = "acct"
  ipv4addr = localhost IPv4 address [127.0.0.1]
  port = 60813
}
Listening on auth address 127.0.0.1 port 60812 bound to server default
Listening on acct address 127.0.0.1 port 60813 bound to server default
Ready to process requests
(0) Received Status-Server Id 14 from 127.0.0.1:36571 to 127.0.0.1:60813
length 70
(0)   Message-Authenticator = 0x46034a1513fb5693229fc1460c1866cc
(0)   NAS-Identifier = "Status Check 1. Are you alive?"
(0) Sent Accounting-Response Id 14 from 127.0.0.1:60813 to 127.0.0.1:36571
length 0
(0) Finished request
Waking up in 1.9 seconds.
(0) <done>: Cleaning up request packet ID 14 with timestamp +23
Ready to process requests



On Fri, Aug 14, 2015 at 10:11 PM, Alan DeKok <aland at deployingradius.com>
wrote:

>   OK... that's just weird.
>
>   What are you doing with the config?   You're clearly in some unusual
> corner case which causes this problem.  I can't see it here, and there have
> been no other reports.
>
>   So... it works 99% of the time.  What causes the problem?
>
>   i.e. start with a default config, test that it works.  Make one change
> to get it closer to your current config, test it again, etc.  When it stops
> working, you've narrowed it down to the one change that causes the problem.
>
>   You don't need to change much... just anything related to proxying and
> status checks.  There's no need to look users up in a DB, etc.
>
>   Unless I know what's different about your system, it will be impossible
> to understand what's going wrong.  And therefore impossible to fix it.
>
>   Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See
> http://www.freeradius.org/list/users.html
>


More information about the Freeradius-Users mailing list