talking to eduroam federation
Rui Ribeiro
ruyrybeyro at gmail.com
Thu Jan 5 22:24:00 CET 2012
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 at 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 at 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 at 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 at 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#
More information about the Freeradius-Users
mailing list