> 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@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 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
