Cheers, I´m in the testing phase of a freeradius for the EDUROAM federation; local users are working ok authenticated against an AD, but when I proxy for the federation, users loose attributes, like Service-Type = "Framed-User", and is all zeros like "Message-Authenticator = 0x00000000000000000000000000000000". Obviously the request is denied by the federation, while a radtest works fine. In proxy.conf I have: realm DEFAULT { type = radius authhost = federation_server:1812 accthost =federation_server:1813 secret = xxxxxxxx nostrip } My pre-proxy at the moment is: pre-proxy { # files # attr_filter.pre-proxy # If you want to have a log of packets proxied to a home # server, un-comment the following line, and the # 'detail pre_proxy_log' section, above. pre_proxy_log # if (Packet-Type != Accounting-Request) { # attr_filter.pre-proxy # } } I´ve already tried some approaches and at the moment I am quite at loss of how to tackle this problem. Some ideas? Best regards, Rui Ribeiro Here comes the debugging: !free freeradius -Xxxxxx Thu Jan 5 21:14:05 2012 : Info: FreeRADIUS Version 2.1.10, for host i486-pc-linux-gnu, built on Nov 14 2010 at 20:41:03 Thu Jan 5 21:14:05 2012 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. Thu Jan 5 21:14:05 2012 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Thu Jan 5 21:14:05 2012 : Info: PARTICULAR PURPOSE. Thu Jan 5 21:14:05 2012 : Info: You may redistribute copies of FreeRADIUS under the terms of the Thu Jan 5 21:14:05 2012 : Info: GNU General Public License v2. Thu Jan 5 21:14:05 2012 : Info: Starting - reading configuration files ... Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/radiusd.conf Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/proxy.conf Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/clients.conf Thu Jan 5 21:14:05 2012 : Debug: including files in directory /etc/freeradius/modules/ Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/smsotp Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/policy Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/counter Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/checkval Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/detail Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/radutmp Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/detail.log Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/ntlm_auth Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/mac2ip Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/perl Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/otp Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/ippool Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/linelog Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/detail.example.com Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/f_ticks Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/attr_rewrite Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/preprocess Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/attr_filter Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/always Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/sql_log Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/smbpasswd Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/files Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/unix Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/ldap Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/sradutmp Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/expiration Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/inner-eap Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/mschap Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/mac2vlan Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/krb5 Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/passwd Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/pam Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/realm Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/wimax Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/chap Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/exec Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/expr Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/acct_unique Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/cui Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/opendirectory Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/dynamic_clients Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/echo Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/etc_group Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/pap Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/logintime Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/modules/digest Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/eap.conf Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/policy.conf Thu Jan 5 21:14:05 2012 : Debug: including files in directory /etc/freeradius/sites-enabled/ Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/teste.iscte.pt Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/sites-available/default Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/status Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/default Thu Jan 5 21:14:05 2012 : Debug: including configuration file /etc/freeradius/sites-enabled/inner-tunnel Thu Jan 5 21:14:05 2012 : Debug: main { Thu Jan 5 21:14:05 2012 : Debug: user = "freerad" Thu Jan 5 21:14:05 2012 : Debug: group = "freerad" Thu Jan 5 21:14:05 2012 : Debug: allow_core_dumps = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: including dictionary file /etc/freeradius/dictionary Thu Jan 5 21:14:05 2012 : Debug: main { Thu Jan 5 21:14:05 2012 : Debug: prefix = "/usr" Thu Jan 5 21:14:05 2012 : Debug: localstatedir = "/var" Thu Jan 5 21:14:05 2012 : Debug: logdir = "/var/log/freeradius" Thu Jan 5 21:14:05 2012 : Debug: libdir = "/usr/lib/freeradius" Thu Jan 5 21:14:05 2012 : Debug: radacctdir = "/var/log/freeradius/radacct" Thu Jan 5 21:14:05 2012 : Debug: hostname_lookups = no Thu Jan 5 21:14:05 2012 : Debug: max_request_time = 30 Thu Jan 5 21:14:05 2012 : Debug: cleanup_delay = 5 Thu Jan 5 21:14:05 2012 : Debug: max_requests = 256000 Thu Jan 5 21:14:05 2012 : Debug: pidfile = "/var/run/freeradius/freeradius.pid" Thu Jan 5 21:14:05 2012 : Debug: checkrad = "/usr/sbin/checkrad" Thu Jan 5 21:14:05 2012 : Debug: debug_level = 0 Thu Jan 5 21:14:05 2012 : Debug: proxy_requests = yes Thu Jan 5 21:14:05 2012 : Debug: log { Thu Jan 5 21:14:05 2012 : Debug: stripped_names = yes Thu Jan 5 21:14:05 2012 : Debug: auth = yes Thu Jan 5 21:14:05 2012 : Debug: auth_badpass = yes Thu Jan 5 21:14:05 2012 : Debug: auth_goodpass = yes Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: security { Thu Jan 5 21:14:05 2012 : Debug: max_attributes = 200 Thu Jan 5 21:14:05 2012 : Debug: reject_delay = 0 Thu Jan 5 21:14:05 2012 : Debug: status_server = yes Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: radiusd: #### Loading Realms and Home Servers #### Thu Jan 5 21:14:05 2012 : Debug: proxy server { Thu Jan 5 21:14:05 2012 : Debug: retry_delay = 5 Thu Jan 5 21:14:05 2012 : Debug: retry_count = 1 Thu Jan 5 21:14:05 2012 : Debug: default_fallback = no Thu Jan 5 21:14:05 2012 : Debug: dead_time = 120 Thu Jan 5 21:14:05 2012 : Debug: wake_all_if_all_dead = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: realm iscte.pt { Thu Jan 5 21:14:05 2012 : Debug: authhost = LOCAL Thu Jan 5 21:14:05 2012 : Debug: accthost = LOCAL Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: realm teste.iscte.pt { Thu Jan 5 21:14:05 2012 : Debug: authhost = LOCAL Thu Jan 5 21:14:05 2012 : Debug: accthost = LOCAL Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: realm NULL { Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: realm DEFAULT { Thu Jan 5 21:14:05 2012 : Debug: nostrip Thu Jan 5 21:14:05 2012 : Debug: authhost = 193.136.192.43:1812 Thu Jan 5 21:14:05 2012 : Debug: accthost = 193.136.192.43:1813 Thu Jan 5 21:14:05 2012 : Debug: secret = xxxxxxxxxx Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: realm DEFAULT { Thu Jan 5 21:14:05 2012 : Debug: authhost = 193.136.192.44:1812 Thu Jan 5 21:14:05 2012 : Debug: accthost = 193.136.192.44:1813 Thu Jan 5 21:14:05 2012 : Debug: secret = xxxxxxxxxx Thu Jan 5 21:14:05 2012 : Debug: } # realm DEFAULT Thu Jan 5 21:14:05 2012 : Debug: radiusd: #### Loading Clients #### Thu Jan 5 21:14:05 2012 : Debug: client localhost { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: nastype = "other" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 193.136.188.36 { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 193.136.188.36 Thu Jan 5 21:14:05 2012 : Debug: netmask = 32 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: nastype = "other" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 10.10.32.25 { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 10.10.32.25 Thu Jan 5 21:14:05 2012 : Debug: netmask = 32 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: nastype = "other" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 10.10.66.18/32 { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 10.10.66.18 Thu Jan 5 21:14:05 2012 : Debug: netmask = 32 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "nut" Thu Jan 5 21:14:05 2012 : Debug: nastype = "other" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 10.10.65.0/24 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "rede1_aps" Thu Jan 5 21:14:05 2012 : Debug: nastype = "cisco" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 10.10.66.0/24 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "rede2_aps" Thu Jan 5 21:14:05 2012 : Debug: nastype = "cisco" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 10.10.32.0/22 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "eduroam2" Thu Jan 5 21:14:05 2012 : Debug: nastype = "other" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 193.136.192.119 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "proxyNacional" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 193.136.192.43 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "proxyNacional1" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client 193.136.192.44 { Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: shortname = "proxyNacional2" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: radiusd: #### Instantiating modules #### Thu Jan 5 21:14:05 2012 : Debug: instantiate { Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_exec, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_exec Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "exec" from file /etc/freeradius/modules/exec Thu Jan 5 21:14:05 2012 : Debug: exec { Thu Jan 5 21:14:05 2012 : Debug: wait = no Thu Jan 5 21:14:05 2012 : Debug: input_pairs = "request" Thu Jan 5 21:14:05 2012 : Debug: shell_escape = yes Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_expr, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_expr Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_expiration, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_expiration Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration Thu Jan 5 21:14:05 2012 : Debug: expiration { Thu Jan 5 21:14:05 2012 : Debug: reply-message = "Password Has Expired " Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_logintime, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_logintime Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime Thu Jan 5 21:14:05 2012 : Debug: logintime { Thu Jan 5 21:14:05 2012 : Debug: reply-message = "You are calling outside your allowed timespan " Thu Jan 5 21:14:05 2012 : Debug: minimum-timeout = 60 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: radiusd: #### Loading Virtual Servers #### Thu Jan 5 21:14:05 2012 : Debug: server teste.iscte.pt { # from file /etc/freeradius/sites-enabled/teste.iscte.pt Thu Jan 5 21:14:05 2012 : Debug: modules { Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_mschap, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_mschap Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap Thu Jan 5 21:14:05 2012 : Debug: mschap { Thu Jan 5 21:14:05 2012 : Debug: use_mppe = yes Thu Jan 5 21:14:05 2012 : Debug: require_encryption = yes Thu Jan 5 21:14:05 2012 : Debug: require_strong = yes Thu Jan 5 21:14:05 2012 : Debug: with_ntdomain_hack = yes Thu Jan 5 21:14:05 2012 : Debug: ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} --challenge=%{mschap:Challenge:-00} --domain=IUL --nt-response=%{mschap:NT-Response:-00}" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_eap, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_eap Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "eap" from file /etc/freeradius/eap.conf Thu Jan 5 21:14:05 2012 : Debug: eap { Thu Jan 5 21:14:05 2012 : Debug: default_eap_type = "peap" Thu Jan 5 21:14:05 2012 : Debug: timer_expire = 60 Thu Jan 5 21:14:05 2012 : Debug: ignore_unknown_eap_types = no Thu Jan 5 21:14:05 2012 : Debug: cisco_accounting_username_bug = no Thu Jan 5 21:14:05 2012 : Debug: max_sessions = 4096 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating eap-mschapv2 Thu Jan 5 21:14:05 2012 : Debug: mschapv2 { Thu Jan 5 21:14:05 2012 : Debug: with_ntdomain_hack = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to sub-module rlm_eap_tls Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating eap-tls Thu Jan 5 21:14:05 2012 : Debug: tls { Thu Jan 5 21:14:05 2012 : Debug: rsa_key_exchange = no Thu Jan 5 21:14:05 2012 : Debug: dh_key_exchange = yes Thu Jan 5 21:14:05 2012 : Debug: rsa_key_length = 512 Thu Jan 5 21:14:05 2012 : Debug: dh_key_length = 512 Thu Jan 5 21:14:05 2012 : Debug: verify_depth = 0 Thu Jan 5 21:14:05 2012 : Debug: CA_path = "/etc/freeradius/certs" Thu Jan 5 21:14:05 2012 : Debug: pem_file_type = yes Thu Jan 5 21:14:05 2012 : Debug: private_key_file = "/etc/freeradius/certs/server.key" Thu Jan 5 21:14:05 2012 : Debug: certificate_file = "/etc/freeradius/certs/server.pem" Thu Jan 5 21:14:05 2012 : Debug: CA_file = "/etc/freeradius/certs/ca.pem" Thu Jan 5 21:14:05 2012 : Debug: private_key_password = "xxxxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: dh_file = "/etc/freeradius/certs/dh" Thu Jan 5 21:14:05 2012 : Debug: random_file = "/dev/urandom" Thu Jan 5 21:14:05 2012 : Debug: fragment_size = 1024 Thu Jan 5 21:14:05 2012 : Debug: include_length = yes Thu Jan 5 21:14:05 2012 : Debug: check_crl = no Thu Jan 5 21:14:05 2012 : Debug: cipher_list = "DEFAULT" Thu Jan 5 21:14:05 2012 : Debug: make_cert_command = "/etc/freeradius/certs/bootstrap" Thu Jan 5 21:14:05 2012 : Debug: cache { Thu Jan 5 21:14:05 2012 : Debug: enable = no Thu Jan 5 21:14:05 2012 : Debug: lifetime = 24 Thu Jan 5 21:14:05 2012 : Debug: max_entries = 255 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: verify { Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to sub-module rlm_eap_ttls Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating eap-ttls Thu Jan 5 21:14:05 2012 : Debug: ttls { Thu Jan 5 21:14:05 2012 : Debug: default_eap_type = "mschapv2" Thu Jan 5 21:14:05 2012 : Debug: copy_request_to_tunnel = yes Thu Jan 5 21:14:05 2012 : Debug: use_tunneled_reply = yes Thu Jan 5 21:14:05 2012 : Debug: virtual_server = "inner-tunnel" Thu Jan 5 21:14:05 2012 : Debug: include_length = yes Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to sub-module rlm_eap_peap Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating eap-peap Thu Jan 5 21:14:05 2012 : Debug: peap { Thu Jan 5 21:14:05 2012 : Debug: default_eap_type = "mschapv2" Thu Jan 5 21:14:05 2012 : Debug: copy_request_to_tunnel = yes Thu Jan 5 21:14:05 2012 : Debug: use_tunneled_reply = yes Thu Jan 5 21:14:05 2012 : Debug: proxy_tunneled_request_as_eap = yes Thu Jan 5 21:14:05 2012 : Debug: virtual_server = "inner-tunnel" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating eap-mschapv2 Thu Jan 5 21:14:05 2012 : Debug: mschapv2 { Thu Jan 5 21:14:05 2012 : Debug: with_ntdomain_hack = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_preprocess, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_preprocess Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess Thu Jan 5 21:14:05 2012 : Debug: preprocess { Thu Jan 5 21:14:05 2012 : Debug: huntgroups = "/etc/freeradius/huntgroups" Thu Jan 5 21:14:05 2012 : Debug: hints = "/etc/freeradius/hints" Thu Jan 5 21:14:05 2012 : Debug: with_ascend_hack = no Thu Jan 5 21:14:05 2012 : Debug: ascend_channels_per_line = 23 Thu Jan 5 21:14:05 2012 : Debug: with_ntdomain_hack = no Thu Jan 5 21:14:05 2012 : Debug: with_specialix_jetstream_hack = no Thu Jan 5 21:14:05 2012 : Debug: with_cisco_vsa_hack = no Thu Jan 5 21:14:05 2012 : Debug: with_alvarion_vsa_hack = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_detail, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_detail Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "auth_log" from file /etc/freeradius/modules/detail.log Thu Jan 5 21:14:05 2012 : Debug: detail auth_log { Thu Jan 5 21:14:05 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d" Thu Jan 5 21:14:05 2012 : Debug: header = "%t" Thu Jan 5 21:14:05 2012 : Debug: detailperm = 384 Thu Jan 5 21:14:05 2012 : Debug: dirperm = 493 Thu Jan 5 21:14:05 2012 : Debug: locking = no Thu Jan 5 21:14:05 2012 : Debug: log_packet_header = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_realm, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_realm Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm Thu Jan 5 21:14:05 2012 : Debug: realm suffix { Thu Jan 5 21:14:05 2012 : Debug: format = "suffix" Thu Jan 5 21:14:05 2012 : Debug: delimiter = "@" Thu Jan 5 21:14:05 2012 : Debug: ignore_default = no Thu Jan 5 21:14:05 2012 : Debug: ignore_null = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_files, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_files Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "files" from file /etc/freeradius/modules/files Thu Jan 5 21:14:05 2012 : Debug: files { Thu Jan 5 21:14:05 2012 : Debug: usersfile = "/etc/freeradius/users" Thu Jan 5 21:14:05 2012 : Debug: acctusersfile = "/etc/freeradius/acct_users" Thu Jan 5 21:14:05 2012 : Debug: preproxy_usersfile = "/etc/freeradius/preproxy_users" Thu Jan 5 21:14:05 2012 : Debug: compat = "no" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Checking preacct {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking accounting {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "detail" from file /etc/freeradius/modules/detail Thu Jan 5 21:14:05 2012 : Debug: detail { Thu Jan 5 21:14:05 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Thu Jan 5 21:14:05 2012 : Debug: header = "%t" Thu Jan 5 21:14:05 2012 : Debug: detailperm = 384 Thu Jan 5 21:14:05 2012 : Debug: dirperm = 493 Thu Jan 5 21:14:05 2012 : Debug: locking = no Thu Jan 5 21:14:05 2012 : Debug: log_packet_header = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_counter, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_counter Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "daily" from file /etc/freeradius/modules/counter Thu Jan 5 21:14:05 2012 : Debug: counter daily { Thu Jan 5 21:14:05 2012 : Debug: filename = "/etc/freeradius/db.daily" Thu Jan 5 21:14:05 2012 : Debug: key = "User-Name" Thu Jan 5 21:14:05 2012 : Debug: reset = "daily" Thu Jan 5 21:14:05 2012 : Debug: count-attribute = "Acct-Session-Time" Thu Jan 5 21:14:05 2012 : Debug: counter-name = "Daily-Session-Time" Thu Jan 5 21:14:05 2012 : Debug: check-name = "Max-Daily-Session" Thu Jan 5 21:14:05 2012 : Debug: reply-name = "Session-Timeout" Thu Jan 5 21:14:05 2012 : Debug: allowed-servicetype = "Framed-User" Thu Jan 5 21:14:05 2012 : Debug: cache-size = 5000 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: rlm_counter: Counter attribute Daily-Session-Time is number 11273 Thu Jan 5 21:14:05 2012 : Debug: rlm_counter: Current Time: 1325798045 [2012-01-05 21:14:05], Next reset 1325808000 [2012-01-06 00:00:00] Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_radutmp, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_radutmp Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp Thu Jan 5 21:14:05 2012 : Debug: radutmp { Thu Jan 5 21:14:05 2012 : Debug: filename = "/var/log/freeradius/radutmp" Thu Jan 5 21:14:05 2012 : Debug: username = "%{User-Name}" Thu Jan 5 21:14:05 2012 : Debug: case_sensitive = yes Thu Jan 5 21:14:05 2012 : Debug: check_with_nas = yes Thu Jan 5 21:14:05 2012 : Debug: perm = 384 Thu Jan 5 21:14:05 2012 : Debug: callerid = yes Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "sradutmp" from file /etc/freeradius/modules/sradutmp Thu Jan 5 21:14:05 2012 : Debug: radutmp sradutmp { Thu Jan 5 21:14:05 2012 : Debug: filename = "/var/log/freeradius/sradutmp" Thu Jan 5 21:14:05 2012 : Debug: username = "%{User-Name}" Thu Jan 5 21:14:05 2012 : Debug: case_sensitive = yes Thu Jan 5 21:14:05 2012 : Debug: check_with_nas = yes Thu Jan 5 21:14:05 2012 : Debug: perm = 420 Thu Jan 5 21:14:05 2012 : Debug: callerid = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_always, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_always Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "ok" from file /etc/freeradius/modules/always Thu Jan 5 21:14:05 2012 : Debug: always ok { Thu Jan 5 21:14:05 2012 : Debug: rcode = "ok" Thu Jan 5 21:14:05 2012 : Debug: simulcount = 0 Thu Jan 5 21:14:05 2012 : Debug: mpp = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_attr_filter Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter Thu Jan 5 21:14:05 2012 : Debug: attr_filter attr_filter.accounting_response { Thu Jan 5 21:14:05 2012 : Debug: attrsfile = "/etc/freeradius/attrs.accounting_response" Thu Jan 5 21:14:05 2012 : Debug: key = "%{User-Name}" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Checking session {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking pre-proxy {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "pre_proxy_log" from file /etc/freeradius/modules/detail.log Thu Jan 5 21:14:05 2012 : Debug: detail pre_proxy_log { Thu Jan 5 21:14:05 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d" Thu Jan 5 21:14:05 2012 : Debug: header = "%t" Thu Jan 5 21:14:05 2012 : Debug: detailperm = 384 Thu Jan 5 21:14:05 2012 : Debug: dirperm = 493 Thu Jan 5 21:14:05 2012 : Debug: locking = no Thu Jan 5 21:14:05 2012 : Debug: log_packet_header = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "post_proxy_log" from file /etc/freeradius/modules/detail.log Thu Jan 5 21:14:05 2012 : Debug: detail post_proxy_log { Thu Jan 5 21:14:05 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d" Thu Jan 5 21:14:05 2012 : Debug: header = "%t" Thu Jan 5 21:14:05 2012 : Debug: detailperm = 384 Thu Jan 5 21:14:05 2012 : Debug: dirperm = 493 Thu Jan 5 21:14:05 2012 : Debug: locking = no Thu Jan 5 21:14:05 2012 : Debug: log_packet_header = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "reply_log" from file /etc/freeradius/modules/detail.log Thu Jan 5 21:14:05 2012 : Debug: detail reply_log { Thu Jan 5 21:14:05 2012 : Debug: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d" Thu Jan 5 21:14:05 2012 : Debug: header = "%t" Thu Jan 5 21:14:05 2012 : Debug: detailperm = 384 Thu Jan 5 21:14:05 2012 : Debug: dirperm = 493 Thu Jan 5 21:14:05 2012 : Debug: locking = no Thu Jan 5 21:14:05 2012 : Debug: log_packet_header = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_linelog, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_linelog Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "f_ticks" from file /etc/freeradius/modules/f_ticks Thu Jan 5 21:14:05 2012 : Debug: linelog f_ticks { Thu Jan 5 21:14:05 2012 : Debug: filename = "syslog" Thu Jan 5 21:14:05 2012 : Debug: format = "" Thu Jan 5 21:14:05 2012 : Debug: reference = "f_ticks.%{%{reply:Packet-Type}:-format}" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter Thu Jan 5 21:14:05 2012 : Debug: attr_filter attr_filter.access_reject { Thu Jan 5 21:14:05 2012 : Debug: attrsfile = "/etc/freeradius/attrs.access_reject" Thu Jan 5 21:14:05 2012 : Debug: key = "%{User-Name}" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: } # modules Thu Jan 5 21:14:05 2012 : Debug: } # server Thu Jan 5 21:14:05 2012 : Debug: server status { # from file /etc/freeradius/sites-enabled/status Thu Jan 5 21:14:05 2012 : Debug: modules { Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: } # modules Thu Jan 5 21:14:05 2012 : Debug: } # server Thu Jan 5 21:14:05 2012 : Debug: server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel Thu Jan 5 21:14:05 2012 : Debug: modules { Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking session {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: (Loaded rlm_ldap, checking if it's valid) Thu Jan 5 21:14:05 2012 : Debug: Module: Linked to module rlm_ldap Thu Jan 5 21:14:05 2012 : Debug: Module: Instantiating module "ldap" from file /etc/freeradius/modules/ldap Thu Jan 5 21:14:05 2012 : Debug: ldap { Thu Jan 5 21:14:05 2012 : Debug: server = "x.x.x.x" Thu Jan 5 21:14:05 2012 : Debug: port = 389 Thu Jan 5 21:14:05 2012 : Debug: password = "xxxxx" Thu Jan 5 21:14:05 2012 : Debug: identity = "CN=xxxxx,CN=Users,DC=xxxx,DC=xxxxx" Thu Jan 5 21:14:05 2012 : Debug: net_timeout = 10 Thu Jan 5 21:14:05 2012 : Debug: timeout = 4 Thu Jan 5 21:14:05 2012 : Debug: timelimit = 3 Thu Jan 5 21:14:05 2012 : Debug: tls_mode = no Thu Jan 5 21:14:05 2012 : Debug: start_tls = no Thu Jan 5 21:14:05 2012 : Debug: tls_require_cert = "allow" Thu Jan 5 21:14:05 2012 : Debug: tls { Thu Jan 5 21:14:05 2012 : Debug: start_tls = no Thu Jan 5 21:14:05 2012 : Debug: require_cert = "allow" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: basedn = "cn=Users,dc=xxxxx,dc=xxxxx" Thu Jan 5 21:14:05 2012 : Debug: filter = "(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})" Thu Jan 5 21:14:05 2012 : Debug: base_filter = "(objectclass=radiusprofile)" Thu Jan 5 21:14:05 2012 : Debug: auto_header = no Thu Jan 5 21:14:05 2012 : Debug: access_attr_used_for_allow = yes Thu Jan 5 21:14:05 2012 : Debug: rebind = yes Thu Jan 5 21:14:05 2012 : Debug: groupname_attribute = "sAMAccountName" Thu Jan 5 21:14:05 2012 : Debug: groupmembership_filter = "(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})" Thu Jan 5 21:14:05 2012 : Debug: groupmembership_attribute = "memberOf" Thu Jan 5 21:14:05 2012 : Debug: dictionary_mapping = "/etc/freeradius/ldap.attrmap" Thu Jan 5 21:14:05 2012 : Debug: ldap_debug = 0 Thu Jan 5 21:14:05 2012 : Debug: ldap_connections_number = 5 Thu Jan 5 21:14:05 2012 : Debug: compare_check_items = no Thu Jan 5 21:14:05 2012 : Debug: do_xlat = yes Thu Jan 5 21:14:05 2012 : Debug: edir_account_policy_check = no Thu Jan 5 21:14:05 2012 : Debug: set_auth_type = no Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: Registering ldap_groupcmp for Ldap-Group Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: Registering ldap_xlat with xlat_name ldap Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: reading ldap<->radius mappings from file /etc/freeradius/ldap.attrmap Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to RADIUS $GENERIC$ Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to RADIUS $GENERIC$ Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusAuthType mapped to RADIUS Auth-Type Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusSimultaneousUse mapped to RADIUS Simultaneous-Use Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusCalledStationId mapped to RADIUS Called-Station-Id Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusCallingStationId mapped to RADIUS Calling-Station-Id Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP lmPassword mapped to RADIUS LM-Password Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP ntPassword mapped to RADIUS NT-Password Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP sambaLmPassword mapped to RADIUS LM-Password Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP sambaNtPassword mapped to RADIUS NT-Password Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP dBCSPwd mapped to RADIUS LM-Password Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP userPassword mapped to RADIUS Password-With-Header Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS SMB-Account-CTRL-TEXT Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusExpiration mapped to RADIUS Expiration Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped to RADIUS NAS-IP-Address Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusServiceType mapped to RADIUS Service-Type Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedProtocol mapped to RADIUS Framed-Protocol Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedIPAddress mapped to RADIUS Framed-IP-Address Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask mapped to RADIUS Framed-IP-Netmask Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped to RADIUS Framed-Route Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped to RADIUS Framed-Routing Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFilterId mapped to RADIUS Filter-Id Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to RADIUS Framed-MTU Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedCompression mapped to RADIUS Framed-Compression Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped to RADIUS Login-IP-Host Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginService mapped to RADIUS Login-Service Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped to RADIUS Login-TCP-Port Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusCallbackNumber mapped to RADIUS Callback-Number Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to RADIUS Callback-Id Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork mapped to RADIUS Framed-IPX-Network Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusClass mapped to RADIUS Class Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusSessionTimeout mapped to RADIUS Session-Timeout Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped to RADIUS Idle-Timeout Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusTerminationAction mapped to RADIUS Termination-Action Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginLATService mapped to RADIUS Login-LAT-Service Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped to RADIUS Login-LAT-Node Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped to RADIUS Login-LAT-Group Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink mapped to RADIUS Framed-AppleTalk-Link Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone mapped to RADIUS Framed-AppleTalk-Zone Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to RADIUS Port-Limit Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped to RADIUS Login-LAT-Port Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped to RADIUS Reply-Message Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusTunnelType mapped to RADIUS Tunnel-Type Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusTunnelMediumType mapped to RADIUS Tunnel-Medium-Type Thu Jan 5 21:14:05 2012 : Debug: rlm_ldap: LDAP radiusTunnelPrivateGroupId mapped to RADIUS Tunnel-Private-Group-Id Thu Jan 5 21:14:05 2012 : Debug: conns: 0x97a3e38 Thu Jan 5 21:14:05 2012 : Debug: } # modules Thu Jan 5 21:14:05 2012 : Debug: } # server Thu Jan 5 21:14:05 2012 : Debug: server { # from file /etc/freeradius/radiusd.conf Thu Jan 5 21:14:05 2012 : Debug: modules { Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking preacct {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking accounting {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking session {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking pre-proxy {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Jan 5 21:14:05 2012 : Debug: } # modules Thu Jan 5 21:14:05 2012 : Debug: } # server Thu Jan 5 21:14:05 2012 : Debug: radiusd: #### Opening IP addresses and Ports #### Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "auth" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 10.10.32.25 Thu Jan 5 21:14:05 2012 : Debug: port = 0 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "acct" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 10.10.32.25 Thu Jan 5 21:14:05 2012 : Debug: port = 0 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "auth" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 193.136.188.36 Thu Jan 5 21:14:05 2012 : Debug: port = 0 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "acct" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 193.136.188.36 Thu Jan 5 21:14:05 2012 : Debug: port = 0 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "status" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = * Thu Jan 5 21:14:05 2012 : Debug: port = 18120 Thu Jan 5 21:14:05 2012 : Debug: client admin { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxxx" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: client admin2 { Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 10.10.32.35 Thu Jan 5 21:14:05 2012 : Debug: require_message_authenticator = no Thu Jan 5 21:14:05 2012 : Debug: secret = "xxxxxx" Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "auth" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 5 21:14:05 2012 : Debug: port = 1812 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: listen { Thu Jan 5 21:14:05 2012 : Debug: type = "acct" Thu Jan 5 21:14:05 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 5 21:14:05 2012 : Debug: port = 1813 Thu Jan 5 21:14:05 2012 : Debug: } Thu Jan 5 21:14:05 2012 : Debug: Listening on authentication address 10.10.32.25 port 1812 Thu Jan 5 21:14:05 2012 : Debug: Listening on accounting interface eth0 address 10.10.32.25 port 1813 Thu Jan 5 21:14:05 2012 : Debug: Listening on authentication address 193.136.188.36 port 1812 as server teste.iscte.pt Thu Jan 5 21:14:05 2012 : Debug: Listening on accounting address 193.136.188.36 port 1813 as server teste.iscte.pt Thu Jan 5 21:14:05 2012 : Debug: Listening on status address * port 18120 as server status Thu Jan 5 21:14:05 2012 : Debug: Listening on authentication address 127.0.0.1 port 1812 as server inner-tunnel Thu Jan 5 21:14:05 2012 : Debug: Listening on accounting address 127.0.0.1 port 1813 as server inner-tunnel Thu Jan 5 21:14:05 2012 : Debug: Listening on proxy address 10.10.32.25 port 1814 Thu Jan 5 21:14:05 2012 : Info: Ready to process requests. rad_recv: Access-Request packet from host 10.10.65.135 port 46611, id=93, length=184 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address = 10.10.65.135 NAS-Port = 400 Called-Station-Id = "00-0F-7D-39-2A-12:eduroam2" Calling-Station-Id = "60-C5-47-8B-FF-46" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 13Mbps/6Mbps 802.11n" EAP-Message = 0x020f001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0x2012955096623bb33854fc25a46b8cde Thu Jan 5 21:14:08 2012 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default Thu Jan 5 21:14:08 2012 : Info: +- entering group authorize {...} Thu Jan 5 21:14:08 2012 : Info: ++[preprocess] returns ok Thu Jan 5 21:14:08 2012 : Info: [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.65.135/auth-detail-20120105 Thu Jan 5 21:14:08 2012 : Info: [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.65.135/auth-detail-20120105 Thu Jan 5 21:14:08 2012 : Info: [auth_log] expand: %t -> Thu Jan 5 21:14:08 2012 Thu Jan 5 21:14:08 2012 : Info: ++[auth_log] returns ok Thu Jan 5 21:14:08 2012 : Info: ++[mschap] returns noop Thu Jan 5 21:14:08 2012 : Info: [eap] EAP packet type response id 15 length 23 Thu Jan 5 21:14:08 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Jan 5 21:14:08 2012 : Info: ++[eap] returns updated Thu Jan 5 21:14:08 2012 : Info: [suffix] Looking up realm "roam.fccn.pt" for User-Name = "iscte@roam.fccn.pt" Thu Jan 5 21:14:08 2012 : Info: [suffix] Found realm "DEFAULT" Thu Jan 5 21:14:08 2012 : Info: [suffix] Adding Realm = "DEFAULT" Thu Jan 5 21:14:08 2012 : Info: [suffix] Proxying request from user iscte to realm DEFAULT Thu Jan 5 21:14:08 2012 : Info: [suffix] Preparing to proxy authentication request to realm "DEFAULT" Thu Jan 5 21:14:08 2012 : Info: ++[suffix] returns updated Thu Jan 5 21:14:08 2012 : Info: ++[files] returns noop Thu Jan 5 21:14:08 2012 : Info: ++[expiration] returns noop Thu Jan 5 21:14:08 2012 : Info: ++[logintime] returns noop Thu Jan 5 21:14:08 2012 : Info: # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default Thu Jan 5 21:14:08 2012 : Info: +- entering group pre-proxy {...} Thu Jan 5 21:14:08 2012 : Info: [pre_proxy_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.65.135/pre-proxy-detail-20120105 Thu Jan 5 21:14:08 2012 : Info: [pre_proxy_log] /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.65.135/pre-proxy-detail-20120105 Thu Jan 5 21:14:08 2012 : Info: [pre_proxy_log] expand: %t -> Thu Jan 5 21:14:08 2012 Thu Jan 5 21:14:08 2012 : Info: ++[pre_proxy_log] returns ok Sending Access-Request of id 4 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address = 10.10.65.135 NAS-Port = 400 Called-Station-Id = "00-0F-7D-39-2A-12:eduroam2" Calling-Station-Id = "60-C5-47-8B-FF-46" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 13Mbps/6Mbps 802.11n" EAP-Message = 0x020f001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3933 Thu Jan 5 21:14:08 2012 : Info: Proxying request 0 to home server 193.136.192.43 port 1812 Sending Access-Request of id 4 to 193.136.192.43 port 1812 User-Name = "iscte@roam.fccn.pt" NAS-IP-Address = 10.10.65.135 NAS-Port = 400 Called-Station-Id = "00-0F-7D-39-2A-12:eduroam2" Calling-Station-Id = "60-C5-47-8B-FF-46" Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 13Mbps/6Mbps 802.11n" EAP-Message = 0x020f001701697363746540726f616d2e6663636e2e7074 Message-Authenticator = 0x00000000000000000000000000000000 Proxy-State = 0x3933 Thu Jan 5 21:14:08 2012 : Debug: Going to the next request Thu Jan 5 21:14:08 2012 : Debug: Waking up in 0.9 seconds. Thu Jan 5 21:14:09 2012 : Debug: Waking up in 2.9 seconds. Thu Jan 5 21:14:12 2012 : Error: ASSERT FAILED event.c[1181]: "We do not have threads, but the request is marked as queued or running in a child thread" == NULL Aborted radius:/home/rui#