Packet-Original-Timestamp
Бен Томпсон
b.thompson at latera.ru
Fri Mar 8 09:20:27 CET 2013
> If you could provide a backtrace of the rlm_perl module at the point it gets stuck it'd be helpful. Then we can fix it before someone else runs into the same issue.
Hello Arran
I am not very familiar debugging C programs, but maybe this is will help :-
root at somecomp:~# gdb "/usr/local/sbin/radiusd"
GNU gdb (GDB) 7.0.1-debian
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
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-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/sbin/radiusd...done.
(gdb) run -Xx
Starting program: /usr/local/sbin/radiusd -Xx
[Thread debugging using libthread_db enabled]
Fri Mar 8 12:00:17 2013 : Info: radiusd: FreeRADIUS Version 3.0.0
(git #478fa70), for host , built on Mar 8 2013 at 11:47:09
Fri Mar 8 12:00:17 2013 : Debug: Server was built with:
Fri Mar 8 12:00:17 2013 : Debug: accounting
Fri Mar 8 12:00:17 2013 : Debug: authentication
Fri Mar 8 12:00:17 2013 : Debug: ascend binary attributes
Fri Mar 8 12:00:17 2013 : Debug: coa
Fri Mar 8 12:00:17 2013 : Debug: control-socket
Fri Mar 8 12:00:17 2013 : Debug: detail
Fri Mar 8 12:00:17 2013 : Debug: dhcp
Fri Mar 8 12:00:17 2013 : Debug: dynamic clients
Fri Mar 8 12:00:17 2013 : Debug: proxy
Fri Mar 8 12:00:17 2013 : Debug: regex-posix
Fri Mar 8 12:00:17 2013 : Debug: session-management
Fri Mar 8 12:00:17 2013 : Debug: stats
Fri Mar 8 12:00:17 2013 : Debug: tcp
Fri Mar 8 12:00:17 2013 : Debug: threads
Fri Mar 8 12:00:17 2013 : Debug: tls
Fri Mar 8 12:00:17 2013 : Debug: unlang
Fri Mar 8 12:00:17 2013 : Debug: vmps
Fri Mar 8 12:00:17 2013 : Debug: Server core libs:
Fri Mar 8 12:00:17 2013 : Debug: talloc : 2.0.*
Fri Mar 8 12:00:17 2013 : Debug: ssl : OpenSSL 0.9.8o 01 Jun 2010
Fri Mar 8 12:00:17 2013 : Info: Copyright (C) 1999-2013 The
FreeRADIUS server project and contributors.
Fri Mar 8 12:00:17 2013 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Fri Mar 8 12:00:17 2013 : Info: PARTICULAR PURPOSE.
Fri Mar 8 12:00:17 2013 : Info: You may redistribute copies of
FreeRADIUS under the terms of the
Fri Mar 8 12:00:17 2013 : Info: GNU General Public License.
Fri Mar 8 12:00:17 2013 : Info: For more information about these
matters, see the file named COPYRIGHT.
Fri Mar 8 12:00:17 2013 : Info: Starting - reading configuration files ...
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/radiusd.conf
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/proxy.conf
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/clients.conf
Fri Mar 8 12:00:17 2013 : Debug: including files in directory
/usr/local/etc/raddb/mods-enabled/
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/detail
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/always
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/unix
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/dhcp
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/cache_eap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/counter
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/dynamic_clients
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/preprocess
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/cui
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/../sql/cui/mysql/queries.conf
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/sradutmp
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/detail.log
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/utf8
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/radutmp
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/eap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/wimax
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/echo
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/passwd
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/pap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/attr_rewrite
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/linelog
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/expr
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/chap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/soh
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/checkval
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/logintime
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/replicate
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/ntlm_auth
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/realm
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/files
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/mschap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/inner-eap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/exec
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/perl
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/digest
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/expiration
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/mods-enabled/attr_filter
Fri Mar 8 12:00:17 2013 : Debug: including files in directory
/usr/local/etc/raddb/policy.d/
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/control
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/canonicalization
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/filter
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/dhcp
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/cui
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/accounting
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/eap
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/policy.d/operator-name
Fri Mar 8 12:00:17 2013 : Debug: including files in directory
/usr/local/etc/raddb/sites-enabled/
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
Fri Mar 8 12:00:17 2013 : Debug: including configuration file
/usr/local/etc/raddb/sites-enabled/default
Fri Mar 8 12:00:17 2013 : Debug: main {
Fri Mar 8 12:00:17 2013 : Debug: security {
Fri Mar 8 12:00:17 2013 : Debug: allow_core_dumps = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: including dictionary file
/usr/local/etc/raddb/dictionary
Fri Mar 8 12:00:17 2013 : Debug: main {
Fri Mar 8 12:00:17 2013 : Debug: name = "radiusd"
Fri Mar 8 12:00:17 2013 : Debug: prefix = "/usr/local"
Fri Mar 8 12:00:17 2013 : Debug: localstatedir = "/usr/local/var"
Fri Mar 8 12:00:17 2013 : Debug: sbindir = "/usr/local/sbin"
Fri Mar 8 12:00:17 2013 : Debug: logdir = "/usr/local/var/log/radius"
Fri Mar 8 12:00:17 2013 : Debug: run_dir = "/usr/local/var/run/radiusd"
Fri Mar 8 12:00:17 2013 : Debug: libdir = "/usr/local/lib"
Fri Mar 8 12:00:17 2013 : Debug: radacctdir =
"/usr/local/var/log/radius/radacct"
Fri Mar 8 12:00:17 2013 : Debug: hostname_lookups = no
Fri Mar 8 12:00:17 2013 : Debug: max_request_time = 30
Fri Mar 8 12:00:17 2013 : Debug: cleanup_delay = 5
Fri Mar 8 12:00:17 2013 : Debug: max_requests = 1024
Fri Mar 8 12:00:17 2013 : Debug: pidfile =
"/usr/local/var/run/radiusd/radiusd.pid"
Fri Mar 8 12:00:17 2013 : Debug: checkrad = "/usr/local/sbin/checkrad"
Fri Mar 8 12:00:17 2013 : Debug: debug_level = 0
Fri Mar 8 12:00:17 2013 : Debug: proxy_requests = yes
Fri Mar 8 12:00:17 2013 : Debug: log {
Fri Mar 8 12:00:17 2013 : Debug: stripped_names = no
Fri Mar 8 12:00:17 2013 : Debug: auth = no
Fri Mar 8 12:00:17 2013 : Debug: auth_badpass = no
Fri Mar 8 12:00:17 2013 : Debug: auth_goodpass = no
Fri Mar 8 12:00:17 2013 : Debug: colourise = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: security {
Fri Mar 8 12:00:17 2013 : Debug: max_attributes = 200
Fri Mar 8 12:00:17 2013 : Debug: reject_delay = 1
Fri Mar 8 12:00:17 2013 : Debug: status_server = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: radiusd: #### Loading Realms and
Home Servers ####
Fri Mar 8 12:00:17 2013 : Debug: proxy server {
Fri Mar 8 12:00:17 2013 : Debug: retry_delay = 5
Fri Mar 8 12:00:17 2013 : Debug: retry_count = 3
Fri Mar 8 12:00:17 2013 : Debug: default_fallback = no
Fri Mar 8 12:00:17 2013 : Debug: dead_time = 120
Fri Mar 8 12:00:17 2013 : Debug: wake_all_if_all_dead = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: home_server localhost {
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: port = 1812
Fri Mar 8 12:00:17 2013 : Debug: type = "auth"
Fri Mar 8 12:00:17 2013 : Debug: secret = "testing123"
Fri Mar 8 12:00:17 2013 : Debug: response_window = 20
Fri Mar 8 12:00:17 2013 : Debug: max_outstanding = 65536
Fri Mar 8 12:00:17 2013 : Debug: zombie_period = 40
Fri Mar 8 12:00:17 2013 : Debug: status_check = "status-server"
Fri Mar 8 12:00:17 2013 : Debug: ping_interval = 30
Fri Mar 8 12:00:17 2013 : Debug: check_interval = 30
Fri Mar 8 12:00:17 2013 : Debug: num_answers_to_alive = 3
Fri Mar 8 12:00:17 2013 : Debug: revive_interval = 120
Fri Mar 8 12:00:17 2013 : Debug: status_check_timeout = 4
Fri Mar 8 12:00:17 2013 : Debug: coa {
Fri Mar 8 12:00:17 2013 : Debug: irt = 2
Fri Mar 8 12:00:17 2013 : Debug: mrt = 16
Fri Mar 8 12:00:17 2013 : Debug: mrc = 5
Fri Mar 8 12:00:17 2013 : Debug: mrd = 30
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: limit {
Fri Mar 8 12:00:17 2013 : Debug: max_connections = 16
Fri Mar 8 12:00:17 2013 : Debug: max_requests = 0
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 0
Fri Mar 8 12:00:17 2013 : Debug: idle_timeout = 0
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: home_server_pool my_auth_failover {
Fri Mar 8 12:00:17 2013 : Debug: type = fail-over
Fri Mar 8 12:00:17 2013 : Debug: home_server = localhost
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: realm example.com {
Fri Mar 8 12:00:17 2013 : Debug: auth_pool = my_auth_failover
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: realm LOCAL {
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: radiusd: #### Loading Clients ####
Fri Mar 8 12:00:17 2013 : Debug: client localhost {
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: require_message_authenticator = no
Fri Mar 8 12:00:17 2013 : Debug: secret = "testing123"
Fri Mar 8 12:00:17 2013 : Debug: nastype = "other"
Fri Mar 8 12:00:17 2013 : Debug: proto = "*"
Fri Mar 8 12:00:17 2013 : Debug: limit {
Fri Mar 8 12:00:17 2013 : Debug: max_connections = 16
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 0
Fri Mar 8 12:00:17 2013 : Debug: idle_timeout = 30
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: radiusd: #### Instantiating modules ####
Fri Mar 8 12:00:17 2013 : Debug: instantiate {
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_exec, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_exec
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "exec"
from file /usr/local/etc/raddb/mods-enabled/exec
Fri Mar 8 12:00:17 2013 : Debug: exec {
Fri Mar 8 12:00:17 2013 : Debug: wait = no
Fri Mar 8 12:00:17 2013 : Debug: input_pairs = "request"
Fri Mar 8 12:00:17 2013 : Debug: shell_escape = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_expr, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_expr
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "expr"
from file /usr/local/etc/raddb/mods-enabled/expr
Fri Mar 8 12:00:17 2013 : Debug: expr {
Fri Mar 8 12:00:17 2013 : Debug: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_:
/"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_dhcp, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_dhcp
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "dhcp"
from file /usr/local/etc/raddb/mods-enabled/dhcp
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_expiration, checking
if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_expiration
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"expiration" from file /usr/local/etc/raddb/mods-enabled/expiration
Fri Mar 8 12:00:17 2013 : Debug: expiration {
Fri Mar 8 12:00:17 2013 : Debug: reply-message = "Password Has Expired "
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_logintime, checking
if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_logintime
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"logintime" from file /usr/local/etc/raddb/mods-enabled/logintime
Fri Mar 8 12:00:17 2013 : Debug: logintime {
Fri Mar 8 12:00:17 2013 : Debug: reply-message = "You are calling
outside your allowed timespan "
Fri Mar 8 12:00:17 2013 : Debug: minimum-timeout = 60
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Mar 8 12:00:17 2013 : Debug: server { # from file
/usr/local/etc/raddb/radiusd.conf
Fri Mar 8 12:00:17 2013 : Debug: modules {
Fri Mar 8 12:00:17 2013 : Debug: } # modules
Fri Mar 8 12:00:17 2013 : Debug: } # server
Fri Mar 8 12:00:17 2013 : Debug: server inner-tunnel { # from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
Fri Mar 8 12:00:17 2013 : Debug: modules {
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking authenticate {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_pap, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_pap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "pap"
from file /usr/local/etc/raddb/mods-enabled/pap
Fri Mar 8 12:00:17 2013 : Debug: pap {
Fri Mar 8 12:00:17 2013 : Debug: auto_header = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_chap, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_chap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "chap"
from file /usr/local/etc/raddb/mods-enabled/chap
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_mschap, checking if
it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_mschap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"mschap" from file /usr/local/etc/raddb/mods-enabled/mschap
Fri Mar 8 12:00:17 2013 : Debug: mschap {
Fri Mar 8 12:00:17 2013 : Debug: use_mppe = yes
Fri Mar 8 12:00:17 2013 : Debug: require_encryption = no
Fri Mar 8 12:00:17 2013 : Debug: require_strong = no
Fri Mar 8 12:00:17 2013 : Debug: with_ntdomain_hack = yes
Fri Mar 8 12:00:17 2013 : Debug: passchange {
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: allow_retry = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_unix, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_unix
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "unix"
from file /usr/local/etc/raddb/mods-enabled/unix
Fri Mar 8 12:00:17 2013 : Debug: unix {
Fri Mar 8 12:00:17 2013 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_eap, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_eap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "eap"
from file /usr/local/etc/raddb/mods-enabled/eap
Fri Mar 8 12:00:17 2013 : Debug: eap {
Fri Mar 8 12:00:17 2013 : Debug: default_eap_type = "md5"
Fri Mar 8 12:00:17 2013 : Debug: timer_expire = 60
Fri Mar 8 12:00:17 2013 : Debug: ignore_unknown_eap_types = no
Fri Mar 8 12:00:17 2013 : Debug: cisco_accounting_username_bug = no
Fri Mar 8 12:00:17 2013 : Debug: max_sessions = 4096
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_md5
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-md5
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_leap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-leap
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_gtc
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-gtc
Fri Mar 8 12:00:17 2013 : Debug: gtc {
Fri Mar 8 12:00:17 2013 : Debug: challenge = "Password: "
Fri Mar 8 12:00:17 2013 : Debug: auth_type = "PAP"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_tls
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-tls
Fri Mar 8 12:00:17 2013 : Debug: tls {
Fri Mar 8 12:00:17 2013 : Debug: tls = "tls-common"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: tls-config tls-common {
Fri Mar 8 12:00:17 2013 : Debug: rsa_key_exchange = no
Fri Mar 8 12:00:17 2013 : Debug: dh_key_exchange = yes
Fri Mar 8 12:00:17 2013 : Debug: rsa_key_length = 512
Fri Mar 8 12:00:17 2013 : Debug: dh_key_length = 512
Fri Mar 8 12:00:17 2013 : Debug: verify_depth = 0
Fri Mar 8 12:00:17 2013 : Debug: CA_path = "/usr/local/etc/raddb/certs"
Fri Mar 8 12:00:17 2013 : Debug: pem_file_type = yes
Fri Mar 8 12:00:17 2013 : Debug: private_key_file =
"/usr/local/etc/raddb/certs/server.pem"
Fri Mar 8 12:00:17 2013 : Debug: certificate_file =
"/usr/local/etc/raddb/certs/server.pem"
Fri Mar 8 12:00:17 2013 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem"
Fri Mar 8 12:00:17 2013 : Debug: private_key_password = "whatever"
Fri Mar 8 12:00:17 2013 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh"
Fri Mar 8 12:00:17 2013 : Debug: random_file =
"/usr/local/etc/raddb/certs/random"
Fri Mar 8 12:00:17 2013 : Debug: fragment_size = 1024
Fri Mar 8 12:00:17 2013 : Debug: include_length = yes
Fri Mar 8 12:00:17 2013 : Debug: check_crl = no
Fri Mar 8 12:00:17 2013 : Debug: cipher_list = "DEFAULT"
Fri Mar 8 12:00:17 2013 : Debug: make_cert_command =
"/usr/local/etc/raddb/certs/bootstrap"
Fri Mar 8 12:00:17 2013 : Debug: ecdh_curve = "prime256v1"
Fri Mar 8 12:00:17 2013 : Debug: cache {
Fri Mar 8 12:00:17 2013 : Debug: enable = yes
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 24
Fri Mar 8 12:00:17 2013 : Debug: max_entries = 255
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: verify {
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: ocsp {
Fri Mar 8 12:00:17 2013 : Debug: enable = no
Fri Mar 8 12:00:17 2013 : Debug: override_cert_url = yes
Fri Mar 8 12:00:17 2013 : Debug: url = "http://127.0.0.1/ocsp/"
Fri Mar 8 12:00:17 2013 : Debug: use_nonce = yes
Fri Mar 8 12:00:17 2013 : Debug: timeout = 0
Fri Mar 8 12:00:17 2013 : Debug: softfail = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_ttls
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-ttls
Fri Mar 8 12:00:17 2013 : Debug: ttls {
Fri Mar 8 12:00:17 2013 : Debug: tls = "tls-common"
Fri Mar 8 12:00:17 2013 : Debug: default_eap_type = "md5"
Fri Mar 8 12:00:17 2013 : Debug: copy_request_to_tunnel = no
Fri Mar 8 12:00:17 2013 : Debug: use_tunneled_reply = no
Fri Mar 8 12:00:17 2013 : Debug: virtual_server = "inner-tunnel"
Fri Mar 8 12:00:17 2013 : Debug: include_length = yes
Fri Mar 8 12:00:17 2013 : Debug: require_client_cert = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: debug: Using cached TLS
configuration from previous invocation
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_peap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-peap
Fri Mar 8 12:00:17 2013 : Debug: peap {
Fri Mar 8 12:00:17 2013 : Debug: tls = "tls-common"
Fri Mar 8 12:00:17 2013 : Debug: default_eap_type = "mschapv2"
Fri Mar 8 12:00:17 2013 : Debug: copy_request_to_tunnel = no
Fri Mar 8 12:00:17 2013 : Debug: use_tunneled_reply = no
Fri Mar 8 12:00:17 2013 : Debug: proxy_tunneled_request_as_eap = yes
Fri Mar 8 12:00:17 2013 : Debug: virtual_server = "inner-tunnel"
Fri Mar 8 12:00:17 2013 : Debug: soh = no
Fri Mar 8 12:00:17 2013 : Debug: require_client_cert = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: debug: Using cached TLS
configuration from previous invocation
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to sub-module rlm_eap_mschapv2
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating eap-mschapv2
Fri Mar 8 12:00:17 2013 : Debug: mschapv2 {
Fri Mar 8 12:00:17 2013 : Debug: with_ntdomain_hack = no
Fri Mar 8 12:00:17 2013 : Debug: send_error = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking authorize {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_realm, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_realm
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"suffix" from file /usr/local/etc/raddb/mods-enabled/realm
Fri Mar 8 12:00:17 2013 : Debug: realm suffix {
Fri Mar 8 12:00:17 2013 : Debug: format = "suffix"
Fri Mar 8 12:00:17 2013 : Debug: delimiter = "@"
Fri Mar 8 12:00:17 2013 : Debug: ignore_default = no
Fri Mar 8 12:00:17 2013 : Debug: ignore_null = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_files, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_files
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"files" from file /usr/local/etc/raddb/mods-enabled/files
Fri Mar 8 12:00:17 2013 : Debug: files {
Fri Mar 8 12:00:17 2013 : Debug: usersfile = "/usr/local/etc/raddb/users"
Fri Mar 8 12:00:17 2013 : Debug: acctusersfile =
"/usr/local/etc/raddb/acct_users"
Fri Mar 8 12:00:17 2013 : Debug: preproxy_usersfile =
"/usr/local/etc/raddb/preproxy_users"
Fri Mar 8 12:00:17 2013 : Debug: compat = "no"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/users
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/acct_users
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/preproxy_users
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking session {...} for
more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_radutmp, checking if
it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_radutmp
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"radutmp" from file /usr/local/etc/raddb/mods-enabled/radutmp
Fri Mar 8 12:00:17 2013 : Debug: radutmp {
Fri Mar 8 12:00:17 2013 : Debug: filename =
"/usr/local/var/log/radius/radutmp"
Fri Mar 8 12:00:17 2013 : Debug: username = "%{User-Name}"
Fri Mar 8 12:00:17 2013 : Debug: case_sensitive = yes
Fri Mar 8 12:00:17 2013 : Debug: check_with_nas = yes
Fri Mar 8 12:00:17 2013 : Debug: perm = 384
Fri Mar 8 12:00:17 2013 : Debug: callerid = yes
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking post-proxy {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking post-auth {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_attr_filter,
checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_attr_filter
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"attr_filter.access_reject" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
Fri Mar 8 12:00:17 2013 : Debug: attr_filter attr_filter.access_reject {
Fri Mar 8 12:00:17 2013 : Debug: file =
"/usr/local/etc/raddb/filter/access_reject"
Fri Mar 8 12:00:17 2013 : Debug: key = "%{User-Name}"
Fri Mar 8 12:00:17 2013 : Debug: relaxed = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/filter/access_reject
Fri Mar 8 12:00:17 2013 : Debug: } # modules
Fri Mar 8 12:00:17 2013 : Debug: } # server
Fri Mar 8 12:00:17 2013 : Debug: server default { # from file
/usr/local/etc/raddb/sites-enabled/default
Fri Mar 8 12:00:17 2013 : Debug: modules {
Fri Mar 8 12:00:17 2013 : Debug: Module: Creating Auth-Type = digest
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking authenticate {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_digest, checking if
it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_digest
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"digest" from file /usr/local/etc/raddb/mods-enabled/digest
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking authorize {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: Module: Loading virtual module
filter_username
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_always, checking if
it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_always
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"reject" from file /usr/local/etc/raddb/mods-enabled/always
Fri Mar 8 12:00:17 2013 : Debug: always reject {
Fri Mar 8 12:00:17 2013 : Debug: rcode = "reject"
Fri Mar 8 12:00:17 2013 : Debug: simulcount = 0
Fri Mar 8 12:00:17 2013 : Debug: mpp = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_preprocess, checking
if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_preprocess
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"preprocess" from file /usr/local/etc/raddb/mods-enabled/preprocess
Fri Mar 8 12:00:17 2013 : Debug: preprocess {
Fri Mar 8 12:00:17 2013 : Debug: huntgroups =
"/usr/local/etc/raddb/huntgroups"
Fri Mar 8 12:00:17 2013 : Debug: hints = "/usr/local/etc/raddb/hints"
Fri Mar 8 12:00:17 2013 : Debug: with_ascend_hack = no
Fri Mar 8 12:00:17 2013 : Debug: ascend_channels_per_line = 23
Fri Mar 8 12:00:17 2013 : Debug: with_ntdomain_hack = no
Fri Mar 8 12:00:17 2013 : Debug: with_specialix_jetstream_hack = no
Fri Mar 8 12:00:17 2013 : Debug: with_cisco_vsa_hack = no
Fri Mar 8 12:00:17 2013 : Debug: with_alvarion_vsa_hack = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/huntgroups
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/hints
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_perl, checking if it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_perl
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "perl"
from file /usr/local/etc/raddb/mods-enabled/perl
Fri Mar 8 12:00:17 2013 : Debug: perl {
Fri Mar 8 12:00:17 2013 : Debug: module = "/usr/local/etc/raddb/example.pl"
Fri Mar 8 12:00:17 2013 : Debug: func_authorize = "authorize"
Fri Mar 8 12:00:17 2013 : Debug: func_authenticate = "authenticate"
Fri Mar 8 12:00:17 2013 : Debug: func_accounting = "accounting"
Fri Mar 8 12:00:17 2013 : Debug: func_preacct = "preacct"
Fri Mar 8 12:00:17 2013 : Debug: func_checksimul = "checksimul"
Fri Mar 8 12:00:17 2013 : Debug: func_detach = "detach"
Fri Mar 8 12:00:17 2013 : Debug: func_xlat = "xlat"
Fri Mar 8 12:00:17 2013 : Debug: func_pre_proxy = "pre_proxy"
Fri Mar 8 12:00:17 2013 : Debug: func_post_proxy = "post_proxy"
Fri Mar 8 12:00:17 2013 : Debug: func_post_auth = "post_auth"
Fri Mar 8 12:00:17 2013 : Debug: func_recv_coa = "recv_coa"
Fri Mar 8 12:00:17 2013 : Debug: func_send_coa = "send_coa"
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking preacct {...} for
more modules to load
Fri Mar 8 12:00:17 2013 : Debug: Module: Loading virtual module acct_unique
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking accounting {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: (Loaded rlm_detail, checking if
it's valid)
Fri Mar 8 12:00:17 2013 : Debug: Module: Linked to module rlm_detail
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"detail" from file /usr/local/etc/raddb/mods-enabled/detail
Fri Mar 8 12:00:17 2013 : Debug: detail {
Fri Mar 8 12:00:17 2013 : Debug: detailfile =
"/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Fri Mar 8 12:00:17 2013 : Debug: header = "%t"
Fri Mar 8 12:00:17 2013 : Debug: detailperm = 384
Fri Mar 8 12:00:17 2013 : Debug: dirperm = 493
Fri Mar 8 12:00:17 2013 : Debug: locking = no
Fri Mar 8 12:00:17 2013 : Debug: log_packet_header = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module
"attr_filter.accounting_response" from file
/usr/local/etc/raddb/mods-enabled/attr_filter
Fri Mar 8 12:00:17 2013 : Debug: attr_filter
attr_filter.accounting_response {
Fri Mar 8 12:00:17 2013 : Debug: file =
"/usr/local/etc/raddb/filter/accounting_response"
Fri Mar 8 12:00:17 2013 : Debug: key = "%{User-Name}"
Fri Mar 8 12:00:17 2013 : Debug: relaxed = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: reading pairlist file
/usr/local/etc/raddb/filter/accounting_response
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking post-proxy {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: Module: Checking post-auth {...}
for more modules to load
Fri Mar 8 12:00:17 2013 : Debug: Module: Loading virtual module
remove_reply_message_if_eap
Fri Mar 8 12:00:17 2013 : Debug: Module: Instantiating module "noop"
from file /usr/local/etc/raddb/mods-enabled/always
Fri Mar 8 12:00:17 2013 : Debug: always noop {
Fri Mar 8 12:00:17 2013 : Debug: rcode = "noop"
Fri Mar 8 12:00:17 2013 : Debug: simulcount = 0
Fri Mar 8 12:00:17 2013 : Debug: mpp = no
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Module: Loading virtual module
remove_reply_message_if_eap
Fri Mar 8 12:00:17 2013 : Debug: } # modules
Fri Mar 8 12:00:17 2013 : Debug: } # server
Fri Mar 8 12:00:17 2013 : Debug: radiusd: #### Opening IP addresses
and Ports ####
Fri Mar 8 12:00:17 2013 : Debug: listen {
Fri Mar 8 12:00:17 2013 : Debug: type = "auth"
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: port = 18120
Fri Mar 8 12:00:17 2013 : Debug: max_pps = 0
Fri Mar 8 12:00:17 2013 : Debug: client localhost {
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: require_message_authenticator = no
Fri Mar 8 12:00:17 2013 : Debug: secret = "testing123"
Fri Mar 8 12:00:17 2013 : Debug: nastype = "other"
Fri Mar 8 12:00:17 2013 : Debug: proto = "*"
Fri Mar 8 12:00:17 2013 : Debug: limit {
Fri Mar 8 12:00:17 2013 : Debug: max_connections = 16
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 0
Fri Mar 8 12:00:17 2013 : Debug: idle_timeout = 30
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: listen {
Fri Mar 8 12:00:17 2013 : Debug: type = "auth"
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = *
Fri Mar 8 12:00:17 2013 : Debug: port = 0
Fri Mar 8 12:00:17 2013 : Debug: max_pps = 0
Fri Mar 8 12:00:17 2013 : Debug: client localhost {
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: require_message_authenticator = no
Fri Mar 8 12:00:17 2013 : Debug: secret = "testing123"
Fri Mar 8 12:00:17 2013 : Debug: nastype = "other"
Fri Mar 8 12:00:17 2013 : Debug: proto = "*"
Fri Mar 8 12:00:17 2013 : Debug: limit {
Fri Mar 8 12:00:17 2013 : Debug: max_connections = 16
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 0
Fri Mar 8 12:00:17 2013 : Debug: idle_timeout = 30
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: listen {
Fri Mar 8 12:00:17 2013 : Debug: type = "acct"
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = *
Fri Mar 8 12:00:17 2013 : Debug: port = 0
Fri Mar 8 12:00:17 2013 : Debug: max_pps = 0
Fri Mar 8 12:00:17 2013 : Debug: client localhost {
Fri Mar 8 12:00:17 2013 : Debug: ipaddr = 127.0.0.1
Fri Mar 8 12:00:17 2013 : Debug: require_message_authenticator = no
Fri Mar 8 12:00:17 2013 : Debug: secret = "testing123"
Fri Mar 8 12:00:17 2013 : Debug: nastype = "other"
Fri Mar 8 12:00:17 2013 : Debug: proto = "*"
Fri Mar 8 12:00:17 2013 : Debug: limit {
Fri Mar 8 12:00:17 2013 : Debug: max_connections = 16
Fri Mar 8 12:00:17 2013 : Debug: lifetime = 0
Fri Mar 8 12:00:17 2013 : Debug: idle_timeout = 30
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: }
Fri Mar 8 12:00:17 2013 : Debug: Listening on authentication address
127.0.0.1 port 18120 as server inner-tunnel
Fri Mar 8 12:00:17 2013 : Debug: Listening on authentication address
* port 1812 as server default
Fri Mar 8 12:00:17 2013 : Debug: Listening on accounting address *
port 1813 as server default
Fri Mar 8 12:00:17 2013 : Debug: Opening new proxy address * port 1814
Fri Mar 8 12:00:17 2013 : Debug: Listening on proxy address * port 1814
Fri Mar 8 12:00:17 2013 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 54094,
id=116, length=71
User-Name = "a"
User-Password = "b"
NAS-IP-Address = 127.0.1.1
NAS-Port = 1
Message-Authenticator = 0x7fa9bd07e8fce2f52190b8e737312310
Fri Mar 8 12:00:23 2013 : Debug: (0) # Executing section authorize
from file /usr/local/etc/raddb/sites-enabled/default
Fri Mar 8 12:00:23 2013 : Debug: (0) group authorize {
Fri Mar 8 12:00:23 2013 : Debug: (0) - entering group authorize {...}
Fri Mar 8 12:00:23 2013 : Debug: (0) policy filter_username {
Fri Mar 8 12:00:23 2013 : Debug: (0) - entering policy filter_username {...}
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name !=
"%{tolower:%{User-Name}}")
Fri Mar 8 12:00:23 2013 : Debug: (0) radius_xlat: Running registered
xlat function of module tolower for string '%{User-Name}'
Fri Mar 8 12:00:23 2013 : Debug: (0) expand: '%{User-Name}' -> 'a'
Fri Mar 8 12:00:23 2013 : Debug: (0) expand: '%{tolower:%{User-Name}}' -> 'a'
Fri Mar 8 12:00:23 2013 : Debug: (0) paircmp -> 0
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name !=
"%{tolower:%{User-Name}}") -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name !=
"%{tolower:%{User-Name}}") -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ / /)
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name =~ / /) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ / /) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /@.*@/ )
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name =~
/@.*@/) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /@.*@/ ) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /\\.\\./ )
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name =~
/\\.\\./) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /\\.\\./ ) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if ((User-Name =~ /@/) &&
(User-Name !~ /@(.+)\\.(.+)$/))
Fri Mar 8 12:00:23 2013 : Debug: (0) ?? Evaluating (User-Name =~ /@/) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ?? Skipping (User-Name !~ /@(.+)\\.(.+)$/)
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if ((User-Name =~ /@/) &&
(User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /\\.$/)
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name =~
/\\.$/) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /\\.$/) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /@\\./)
Fri Mar 8 12:00:23 2013 : Debug: (0) ? Evaluating (User-Name =~
/@\\./) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) ? if (User-Name =~ /@\\./) -> FALSE
Fri Mar 8 12:00:23 2013 : Debug: (0) - policy filter_username
returns notfound
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [preprocess] = ok
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
chap (rlm_chap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from chap (rlm_chap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [chap] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
mschap (rlm_mschap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from mschap (rlm_mschap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [mschap] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
digest (rlm_digest) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from digest (rlm_digest) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [digest] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
suffix (rlm_realm) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) suffix : No '@' in User-Name =
"a", looking up realm NULL
Fri Mar 8 12:00:23 2013 : Debug: (0) suffix : No such realm "NULL"
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from suffix (rlm_realm) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [suffix] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
eap (rlm_eap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) eap : No EAP-Message, not doing EAP
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from eap (rlm_eap) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [eap] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
files (rlm_files) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: returned
from files (rlm_files) for request 0
Fri Mar 8 12:00:23 2013 : Debug: (0) [files] = noop
Fri Mar 8 12:00:23 2013 : Debug: (0) modsingle[authorize]: calling
perl (rlm_perl) for request 0
^C
Program received signal SIGINT, Interrupt.
0x00007ffff6425401 in ?? () from /lib/libc.so.6
(gdb) bt
#0 0x00007ffff6425401 in ?? () from /lib/libc.so.6
#1 0x00007ffff6427c70 in malloc () from /lib/libc.so.6
#2 0x00007ffff77941e9 in _talloc_zero () from /usr/lib/libtalloc.so.2
#3 0x00007ffff7bc484a in pairalloc (ctx=0x0, da=0x6dcff8) at
src/lib/valuepair.c:62
#4 0x00007ffff7bc4c96 in paircopyvp (vp=0xa17310) at src/lib/valuepair.c:312
#5 0x00007ffff7bc4f69 in paircopy2 (vp=0xa17310, attr=1, vendor=0,
tag=0 '\000') at src/lib/valuepair.c:418
#6 0x00007ffff2f332a2 in perl_store_vps (vp=0x997c50,
rad_hv=0x9eb820) at src/modules/rlm_perl/rlm_perl.c:555
#7 0x00007ffff2f33ad8 in rlmperl_call (instance=0x864110,
request=0x997980, function_name=0x864330 "authorize") at
src/modules/rlm_perl/rlm_perl.c:710
#8 0x00007ffff2f34343 in perl_authorize (instance=0x864110,
request=0x997980) at src/modules/rlm_perl/rlm_perl.c:814
#9 0x00000000004299df in call_modsingle (component=1, sp=0x87f2a0,
request=0x997980) at src/main/modcall.c:305
#10 0x000000000042add7 in modcall (component=1, c=0x860140,
request=0x997980) at src/main/modcall.c:795
#11 0x000000000042780b in indexed_modcall (comp=1, idx=0,
request=0x997980) at src/main/modules.c:818
#12 0x000000000042918e in module_authorize (autz_type=0,
request=0x997980) at src/main/modules.c:1663
#13 0x000000000040e87a in rad_authenticate (request=0x997980) at
src/main/auth.c:444
#14 0x000000000043eb2e in request_running (request=0x997980, action=1)
at src/main/process.c:1197
#15 0x000000000043ddfe in request_queue_or_run (request=0x997980,
process=0x43ea6c <request_running>) at src/main/process.c:824
#16 0x000000000043f40b in request_insert (listener=0x9947c0,
packet=0x9978a0, client=0x9961c0, fun=0x40e66b <rad_authenticate>,
pnow=0x7fffffffe680) at src/main/process.c:1454
#17 0x000000000043f016 in request_receive (listener=0x9947c0,
packet=0x9978a0, client=0x9961c0, fun=0x40e66b <rad_authenticate>) at
src/main/process.c:1349
#18 0x000000000041b0a5 in auth_socket_recv (listener=0x9947c0) at
src/main/listen.c:1465
#19 0x00000000004443b8 in event_socket_handler (xel=0x97def0, fd=6,
ctx=0x9947c0) at src/main/process.c:3441
#20 0x00007ffff7bca516 in fr_event_loop (el=0x97def0) at src/lib/event.c:415
#21 0x0000000000445554 in radius_event_process () at src/main/process.c:4230
#22 0x000000000042e262 in main (argc=2, argv=0x7fffffffebd8) at
src/main/radiusd.c:439
(gdb)
The steps to reproduce were :-
1. Compile FreeRADIUS from the git master (./configure with no options)
2. fix the symlinks in /usr/local/etc/raddb/sites-enabled
3. add a symlink to the perl module in mods-enabled
4. add a call to the perl module in the authentication section of
sites-enabled/devault
5. run radtest with any random user/pass
You might want to check what happend with the symlinks in raddb/sites-enabled.
Hope this helps
Ben
More information about the Freeradius-Users
mailing list