FreeRadius going through ISA to reach federation
Rui Ribeiro
ruyrybeyro at gmail.com
Fri Dec 16 15:29:13 CET 2011
Hi all,
I have configuring a FreeRadius, and I need to go through a IAS to reach the
eduroam federation. I created a realm for our local domain, created a
DEFAULT proxy for users with other domains pointing to the IAS server, both
are as clients of each other, share the same secret, and also defined a
Remote access policy in IAS.
Tried already some alternatives, and inserted Reply-Message = "Yes", as
suggested on another post in the list.
Despite all the efforts, when talking with the IAS, I receive back the error
Proxy-State = 0x3137.
Any advice?
Best Regards,
Rui Ribeiro
--
freeradius -Xxxxx
Fri Dec 16 12:27:20 2011 : Info: FreeRADIUS Version 2.1.10, for host
i486-pc-linux-gnu, built on Nov 14 2010 at 20:41:03
Fri Dec 16 12:27:20 2011 : Info: Copyright (C) 1999-2009 The FreeRADIUS
server project and contributors.
Fri Dec 16 12:27:20 2011 : Info: There is NO warranty; not even for
MERCHANTABILITY or FITNESS FOR A
Fri Dec 16 12:27:20 2011 : Info: PARTICULAR PURPOSE.
Fri Dec 16 12:27:20 2011 : Info: You may redistribute copies of FreeRADIUS
under the terms of the
Fri Dec 16 12:27:20 2011 : Info: GNU General Public License v2.
Fri Dec 16 12:27:20 2011 : Info: Starting - reading configuration files ...
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/radiusd.conf
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/proxy.conf
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/clients.conf
Fri Dec 16 12:27:20 2011 : Debug: including files in directory
/etc/freeradius/modules/
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/smsotp
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/policy
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/sqlcounter_expire_on_login
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/counter
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/checkval
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/detail
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/radutmp
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/detail.log
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/ntlm_auth
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/mac2ip
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/perl
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/otp
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/ippool
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/linelog
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/detail.example.com
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/attr_rewrite
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/preprocess
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/attr_filter
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/always
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/sql_log
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/smbpasswd
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/files
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/unix
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/ldap
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/sradutmp
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/expiration
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/inner-eap
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/mschap
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/mac2vlan
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/krb5
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/passwd
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/pam
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/realm
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/wimax
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/chap
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/exec
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/expr
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/acct_unique
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/cui
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/opendirectory
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/dynamic_clients
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/echo
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/etc_group
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/pap
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/logintime
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/modules/digest
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/eap.conf
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/policy.conf
Fri Dec 16 12:27:20 2011 : Debug: including files in directory
/etc/freeradius/sites-enabled/
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/sites-enabled/default
Fri Dec 16 12:27:20 2011 : Debug: including configuration file
/etc/freeradius/sites-enabled/inner-tunnel
Fri Dec 16 12:27:20 2011 : Debug: main {
Fri Dec 16 12:27:20 2011 : Debug: user = "freerad"
Fri Dec 16 12:27:20 2011 : Debug: group = "freerad"
Fri Dec 16 12:27:20 2011 : Debug: allow_core_dumps = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: including dictionary file
/etc/freeradius/dictionary
Fri Dec 16 12:27:20 2011 : Debug: main {
Fri Dec 16 12:27:20 2011 : Debug: prefix = "/usr"
Fri Dec 16 12:27:20 2011 : Debug: localstatedir = "/var"
Fri Dec 16 12:27:20 2011 : Debug: logdir = "/var/log/freeradius"
Fri Dec 16 12:27:20 2011 : Debug: libdir = "/usr/lib/freeradius"
Fri Dec 16 12:27:20 2011 : Debug: radacctdir =
"/var/log/freeradius/radacct"
Fri Dec 16 12:27:20 2011 : Debug: hostname_lookups = no
Fri Dec 16 12:27:20 2011 : Debug: max_request_time = 30
Fri Dec 16 12:27:20 2011 : Debug: cleanup_delay = 5
Fri Dec 16 12:27:20 2011 : Debug: max_requests = 1024
Fri Dec 16 12:27:20 2011 : Debug: pidfile =
"/var/run/freeradius/freeradius.pid"
Fri Dec 16 12:27:20 2011 : Debug: checkrad = "/usr/sbin/checkrad"
Fri Dec 16 12:27:20 2011 : Debug: debug_level = 0
Fri Dec 16 12:27:20 2011 : Debug: proxy_requests = yes
Fri Dec 16 12:27:20 2011 : Debug: log {
Fri Dec 16 12:27:20 2011 : Debug: stripped_names = no
Fri Dec 16 12:27:20 2011 : Debug: auth = no
Fri Dec 16 12:27:20 2011 : Debug: auth_badpass = no
Fri Dec 16 12:27:20 2011 : Debug: auth_goodpass = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: security {
Fri Dec 16 12:27:20 2011 : Debug: max_attributes = 200
Fri Dec 16 12:27:20 2011 : Debug: reject_delay = 0
Fri Dec 16 12:27:20 2011 : Debug: status_server = yes
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Fri Dec 16 12:27:20 2011 : Debug: proxy server {
Fri Dec 16 12:27:20 2011 : Debug: retry_delay = 5
Fri Dec 16 12:27:20 2011 : Debug: retry_count = 1
Fri Dec 16 12:27:20 2011 : Debug: default_fallback = no
Fri Dec 16 12:27:20 2011 : Debug: dead_time = 120
Fri Dec 16 12:27:20 2011 : Debug: wake_all_if_all_dead = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: realm iscte.pt {
Fri Dec 16 12:27:20 2011 : Debug: authhost = LOCAL
Fri Dec 16 12:27:20 2011 : Debug: accthost = LOCAL
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: realm NULL {
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: realm DEFAULT {
Fri Dec 16 12:27:20 2011 : Debug: nostrip
Fri Dec 16 12:27:20 2011 : Debug: authhost = nut.iscte.intranet:1812
Fri Dec 16 12:27:20 2011 : Debug: accthost = nut.iscte.intranet:1813
Fri Dec 16 12:27:20 2011 : Debug: secret = xxx
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: radiusd: #### Loading Clients ####
Fri Dec 16 12:27:20 2011 : Debug: client localhost {
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 127.0.0.1
Fri Dec 16 12:27:20 2011 : Debug: require_message_authenticator = no
Fri Dec 16 12:27:20 2011 : Debug: secret = "xxx"
Fri Dec 16 12:27:20 2011 : Debug: nastype = "other"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: client 10.10.66.18/32 {
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 10.10.66.18
Fri Dec 16 12:27:20 2011 : Debug: netmask = 32
Fri Dec 16 12:27:20 2011 : Debug: require_message_authenticator = no
Fri Dec 16 12:27:20 2011 : Debug: secret = "xxx"
Fri Dec 16 12:27:20 2011 : Debug: shortname = "nut"
Fri Dec 16 12:27:20 2011 : Debug: nastype = "other"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: client 10.65.0.0/16 {
Fri Dec 16 12:27:20 2011 : Debug: require_message_authenticator = no
Fri Dec 16 12:27:20 2011 : Debug: secret = "xxxx"
Fri Dec 16 12:27:20 2011 : Debug: shortname = "rede_aps"
Fri Dec 16 12:27:20 2011 : Debug: nastype = "cisco"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: client 10.10.32.0/22 {
Fri Dec 16 12:27:20 2011 : Debug: require_message_authenticator = no
Fri Dec 16 12:27:20 2011 : Debug: secret = "xxx"
Fri Dec 16 12:27:20 2011 : Debug: shortname = "eduroam2"
Fri Dec 16 12:27:20 2011 : Debug: nastype = "other"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: radiusd: #### Instantiating modules ####
Fri Dec 16 12:27:20 2011 : Debug: instantiate {
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_exec, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_exec
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "exec" from
file /etc/freeradius/modules/exec
Fri Dec 16 12:27:20 2011 : Debug: exec {
Fri Dec 16 12:27:20 2011 : Debug: wait = no
Fri Dec 16 12:27:20 2011 : Debug: input_pairs = "request"
Fri Dec 16 12:27:20 2011 : Debug: shell_escape = yes
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_expr, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_expr
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "expr" from
file /etc/freeradius/modules/expr
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_expiration, checking if
it's valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_expiration
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "expiration"
from file /etc/freeradius/modules/expiration
Fri Dec 16 12:27:20 2011 : Debug: expiration {
Fri Dec 16 12:27:20 2011 : Debug: reply-message = "Password Has Expired "
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_logintime, checking if
it's valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_logintime
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "logintime"
from file /etc/freeradius/modules/logintime
Fri Dec 16 12:27:20 2011 : Debug: logintime {
Fri Dec 16 12:27:20 2011 : Debug: reply-message = "You are calling outside
your allowed timespan "
Fri Dec 16 12:27:20 2011 : Debug: minimum-timeout = 60
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Dec 16 12:27:20 2011 : Debug: server inner-tunnel { # from file
/etc/freeradius/sites-enabled/inner-tunnel
Fri Dec 16 12:27:20 2011 : Debug: modules {
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking authenticate {...} for
more modules to load
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_pap, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_pap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "pap" from
file /etc/freeradius/modules/pap
Fri Dec 16 12:27:20 2011 : Debug: pap {
Fri Dec 16 12:27:20 2011 : Debug: encryption_scheme = "auto"
Fri Dec 16 12:27:20 2011 : Debug: auto_header = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_chap, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_chap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "chap" from
file /etc/freeradius/modules/chap
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_mschap, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_mschap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "mschap"
from file /etc/freeradius/modules/mschap
Fri Dec 16 12:27:20 2011 : Debug: mschap {
Fri Dec 16 12:27:20 2011 : Debug: use_mppe = yes
Fri Dec 16 12:27:20 2011 : Debug: require_encryption = yes
Fri Dec 16 12:27:20 2011 : Debug: require_strong = yes
Fri Dec 16 12:27:20 2011 : Debug: with_ntdomain_hack = yes
Fri Dec 16 12:27:20 2011 : 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}"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_eap, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_eap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "eap" from
file /etc/freeradius/eap.conf
Fri Dec 16 12:27:20 2011 : Debug: eap {
Fri Dec 16 12:27:20 2011 : Debug: default_eap_type = "peap"
Fri Dec 16 12:27:20 2011 : Debug: timer_expire = 60
Fri Dec 16 12:27:20 2011 : Debug: ignore_unknown_eap_types = no
Fri Dec 16 12:27:20 2011 : Debug: cisco_accounting_username_bug = no
Fri Dec 16 12:27:20 2011 : Debug: max_sessions = 4096
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_md5
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-md5
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_leap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-leap
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_gtc
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-gtc
Fri Dec 16 12:27:20 2011 : Debug: gtc {
Fri Dec 16 12:27:20 2011 : Debug: challenge = "Password: "
Fri Dec 16 12:27:20 2011 : Debug: auth_type = "PAP"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_tls
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-tls
Fri Dec 16 12:27:20 2011 : Debug: tls {
Fri Dec 16 12:27:20 2011 : Debug: rsa_key_exchange = no
Fri Dec 16 12:27:20 2011 : Debug: dh_key_exchange = yes
Fri Dec 16 12:27:20 2011 : Debug: rsa_key_length = 512
Fri Dec 16 12:27:20 2011 : Debug: dh_key_length = 512
Fri Dec 16 12:27:20 2011 : Debug: verify_depth = 0
Fri Dec 16 12:27:20 2011 : Debug: CA_path = "/etc/freeradius/certs"
Fri Dec 16 12:27:20 2011 : Debug: pem_file_type = yes
Fri Dec 16 12:27:20 2011 : Debug: private_key_file =
"/etc/freeradius/certs/server.key"
Fri Dec 16 12:27:20 2011 : Debug: certificate_file =
"/etc/freeradius/certs/server.pem"
Fri Dec 16 12:27:20 2011 : Debug: CA_file = "/etc/freeradius/certs/ca.pem"
Fri Dec 16 12:27:20 2011 : Debug: private_key_password = "xxx"
Fri Dec 16 12:27:20 2011 : Debug: dh_file = "/etc/freeradius/certs/dh"
Fri Dec 16 12:27:20 2011 : Debug: random_file = "/dev/urandom"
Fri Dec 16 12:27:20 2011 : Debug: fragment_size = 1024
Fri Dec 16 12:27:20 2011 : Debug: include_length = yes
Fri Dec 16 12:27:20 2011 : Debug: check_crl = no
Fri Dec 16 12:27:20 2011 : Debug: cipher_list = "DEFAULT"
Fri Dec 16 12:27:20 2011 : Debug: make_cert_command =
"/etc/freeradius/certs/bootstrap"
Fri Dec 16 12:27:20 2011 : Debug: cache {
Fri Dec 16 12:27:20 2011 : Debug: enable = no
Fri Dec 16 12:27:20 2011 : Debug: lifetime = 24
Fri Dec 16 12:27:20 2011 : Debug: max_entries = 255
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: verify {
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_ttls
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-ttls
Fri Dec 16 12:27:20 2011 : Debug: ttls {
Fri Dec 16 12:27:20 2011 : Debug: default_eap_type = "mschapv2"
Fri Dec 16 12:27:20 2011 : Debug: copy_request_to_tunnel = yes
Fri Dec 16 12:27:20 2011 : Debug: use_tunneled_reply = yes
Fri Dec 16 12:27:20 2011 : Debug: virtual_server = "inner-tunnel"
Fri Dec 16 12:27:20 2011 : Debug: include_length = yes
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module rlm_eap_peap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-peap
Fri Dec 16 12:27:20 2011 : Debug: peap {
Fri Dec 16 12:27:20 2011 : Debug: default_eap_type = "mschapv2"
Fri Dec 16 12:27:20 2011 : Debug: copy_request_to_tunnel = yes
Fri Dec 16 12:27:20 2011 : Debug: use_tunneled_reply = yes
Fri Dec 16 12:27:20 2011 : Debug: proxy_tunneled_request_as_eap = yes
Fri Dec 16 12:27:20 2011 : Debug: virtual_server = "inner-tunnel"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to sub-module
rlm_eap_mschapv2
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating eap-mschapv2
Fri Dec 16 12:27:20 2011 : Debug: mschapv2 {
Fri Dec 16 12:27:20 2011 : Debug: with_ntdomain_hack = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking authorize {...} for more
modules to load
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_realm, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_realm
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "suffix"
from file /etc/freeradius/modules/realm
Fri Dec 16 12:27:20 2011 : Debug: realm suffix {
Fri Dec 16 12:27:20 2011 : Debug: format = "suffix"
Fri Dec 16 12:27:20 2011 : Debug: delimiter = "@"
Fri Dec 16 12:27:20 2011 : Debug: ignore_default = no
Fri Dec 16 12:27:20 2011 : Debug: ignore_null = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_files, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_files
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "files" from
file /etc/freeradius/modules/files
Fri Dec 16 12:27:20 2011 : Debug: files {
Fri Dec 16 12:27:20 2011 : Debug: usersfile = "/etc/freeradius/users"
Fri Dec 16 12:27:20 2011 : Debug: acctusersfile =
"/etc/freeradius/acct_users"
Fri Dec 16 12:27:20 2011 : Debug: preproxy_usersfile =
"/etc/freeradius/preproxy_users"
Fri Dec 16 12:27:20 2011 : Debug: compat = "no"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking post-proxy {...} for
more modules to load
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking post-auth {...} for more
modules to load
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_ldap, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_ldap
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "ldap" from
file /etc/freeradius/modules/ldap
Fri Dec 16 12:27:20 2011 : Debug: ldap {
Fri Dec 16 12:27:20 2011 : Debug: server = "10.10.32.14"
Fri Dec 16 12:27:20 2011 : Debug: port = 389
Fri Dec 16 12:27:20 2011 : Debug: password = "xxxxxxx"
Fri Dec 16 12:27:20 2011 : Debug: identity =
"CN=------,CN=Users,DC=wiscte,DC=wfarm"
Fri Dec 16 12:27:20 2011 : Debug: net_timeout = 10
Fri Dec 16 12:27:20 2011 : Debug: timeout = 4
Fri Dec 16 12:27:20 2011 : Debug: timelimit = 3
Fri Dec 16 12:27:20 2011 : Debug: tls_mode = no
Fri Dec 16 12:27:20 2011 : Debug: start_tls = no
Fri Dec 16 12:27:20 2011 : Debug: tls_require_cert = "allow"
Fri Dec 16 12:27:20 2011 : Debug: tls {
Fri Dec 16 12:27:20 2011 : Debug: start_tls = no
Fri Dec 16 12:27:20 2011 : Debug: require_cert = "allow"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: basedn = "cn=Users,dc=wiscte,dc=wfarm"
Fri Dec 16 12:27:20 2011 : Debug: filter =
"(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})"
Fri Dec 16 12:27:20 2011 : Debug: base_filter =
"(objectclass=radiusprofile)"
Fri Dec 16 12:27:20 2011 : Debug: auto_header = no
Fri Dec 16 12:27:20 2011 : Debug: access_attr_used_for_allow = yes
Fri Dec 16 12:27:20 2011 : Debug: rebind = yes
Fri Dec 16 12:27:20 2011 : Debug: groupname_attribute = "sAMAccountName"
Fri Dec 16 12:27:20 2011 : Debug: groupmembership_filter =
"(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})"
Fri Dec 16 12:27:20 2011 : Debug: groupmembership_attribute = "memberOf"
Fri Dec 16 12:27:20 2011 : Debug: dictionary_mapping =
"/etc/freeradius/ldap.attrmap"
Fri Dec 16 12:27:20 2011 : Debug: ldap_debug = 0
Fri Dec 16 12:27:20 2011 : Debug: ldap_connections_number = 5
Fri Dec 16 12:27:20 2011 : Debug: compare_check_items = no
Fri Dec 16 12:27:20 2011 : Debug: do_xlat = yes
Fri Dec 16 12:27:20 2011 : Debug: edir_account_policy_check = no
Fri Dec 16 12:27:20 2011 : Debug: set_auth_type = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: Registering ldap_groupcmp for
Ldap-Group
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: Registering ldap_xlat with
xlat_name ldap
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: reading ldap<->radius mappings
from file /etc/freeradius/ldap.attrmap
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusCheckItem mapped to
RADIUS $GENERIC$
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusReplyItem mapped to
RADIUS $GENERIC$
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusAuthType mapped to
RADIUS Auth-Type
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusSimultaneousUse
mapped to RADIUS Simultaneous-Use
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusCalledStationId
mapped to RADIUS Called-Station-Id
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusCallingStationId
mapped to RADIUS Calling-Station-Id
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP lmPassword mapped to RADIUS
LM-Password
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP ntPassword mapped to RADIUS
NT-Password
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP sambaLmPassword mapped to
RADIUS LM-Password
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP sambaNtPassword mapped to
RADIUS NT-Password
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP dBCSPwd mapped to RADIUS
LM-Password
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP userPassword mapped to
RADIUS Password-With-Header
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP acctFlags mapped to RADIUS
SMB-Account-CTRL-TEXT
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusExpiration mapped to
RADIUS Expiration
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusNASIpAddress mapped
to RADIUS NAS-IP-Address
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusServiceType mapped to
RADIUS Service-Type
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedProtocol mapped
to RADIUS Framed-Protocol
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedIPAddress
mapped to RADIUS Framed-IP-Address
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedIPNetmask
mapped to RADIUS Framed-IP-Netmask
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedRoute mapped to
RADIUS Framed-Route
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedRouting mapped
to RADIUS Framed-Routing
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFilterId mapped to
RADIUS Filter-Id
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedMTU mapped to
RADIUS Framed-MTU
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedCompression
mapped to RADIUS Framed-Compression
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginIPHost mapped to
RADIUS Login-IP-Host
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginService mapped
to RADIUS Login-Service
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginTCPPort mapped
to RADIUS Login-TCP-Port
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusCallbackNumber mapped
to RADIUS Callback-Number
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusCallbackId mapped to
RADIUS Callback-Id
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedIPXNetwork
mapped to RADIUS Framed-IPX-Network
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusClass mapped to
RADIUS Class
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusSessionTimeout mapped
to RADIUS Session-Timeout
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusIdleTimeout mapped to
RADIUS Idle-Timeout
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusTerminationAction
mapped to RADIUS Termination-Action
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginLATService
mapped to RADIUS Login-LAT-Service
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginLATNode mapped
to RADIUS Login-LAT-Node
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginLATGroup mapped
to RADIUS Login-LAT-Group
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkLink
mapped to RADIUS Framed-AppleTalk-Link
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP
radiusFramedAppleTalkNetwork mapped to RADIUS Framed-AppleTalk-Network
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusFramedAppleTalkZone
mapped to RADIUS Framed-AppleTalk-Zone
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusPortLimit mapped to
RADIUS Port-Limit
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusLoginLATPort mapped
to RADIUS Login-LAT-Port
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusReplyMessage mapped
to RADIUS Reply-Message
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusTunnelType mapped to
RADIUS Tunnel-Type
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusTunnelMediumType
mapped to RADIUS Tunnel-Medium-Type
Fri Dec 16 12:27:20 2011 : Debug: rlm_ldap: LDAP radiusTunnelPrivateGroupId
mapped to RADIUS Tunnel-Private-Group-Id
Fri Dec 16 12:27:20 2011 : Debug: conns: 0x94f3cd0
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_attr_filter, checking if
it's valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_attr_filter
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module
"attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter
Fri Dec 16 12:27:20 2011 : Debug: attr_filter attr_filter.access_reject {
Fri Dec 16 12:27:20 2011 : Debug: attrsfile =
"/etc/freeradius/attrs.access_reject"
Fri Dec 16 12:27:20 2011 : Debug: key = "%{User-Name}"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: } # modules
Fri Dec 16 12:27:20 2011 : Debug: } # server
Fri Dec 16 12:27:20 2011 : Debug: server { # from file
/etc/freeradius/radiusd.conf
Fri Dec 16 12:27:20 2011 : Debug: modules {
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking authenticate {...} for
more modules to load
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking authorize {...} for more
modules to load
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_preprocess, checking if
it's valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_preprocess
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "preprocess"
from file /etc/freeradius/modules/preprocess
Fri Dec 16 12:27:20 2011 : Debug: preprocess {
Fri Dec 16 12:27:20 2011 : Debug: huntgroups = "/etc/freeradius/huntgroups"
Fri Dec 16 12:27:20 2011 : Debug: hints = "/etc/freeradius/hints"
Fri Dec 16 12:27:20 2011 : Debug: with_ascend_hack = no
Fri Dec 16 12:27:20 2011 : Debug: ascend_channels_per_line = 23
Fri Dec 16 12:27:20 2011 : Debug: with_ntdomain_hack = no
Fri Dec 16 12:27:20 2011 : Debug: with_specialix_jetstream_hack = no
Fri Dec 16 12:27:20 2011 : Debug: with_cisco_vsa_hack = no
Fri Dec 16 12:27:20 2011 : Debug: with_alvarion_vsa_hack = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_detail, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_detail
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "auth_log"
from file /etc/freeradius/modules/detail.log
Fri Dec 16 12:27:20 2011 : Debug: detail auth_log {
Fri Dec 16 12:27:20 2011 : Debug: detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
Fri Dec 16 12:27:20 2011 : Debug: header = "%t"
Fri Dec 16 12:27:20 2011 : Debug: detailperm = 384
Fri Dec 16 12:27:20 2011 : Debug: dirperm = 493
Fri Dec 16 12:27:20 2011 : Debug: locking = no
Fri Dec 16 12:27:20 2011 : Debug: log_packet_header = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking preacct {...} for more
modules to load
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking accounting {...} for
more modules to load
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "detail"
from file /etc/freeradius/modules/detail
Fri Dec 16 12:27:20 2011 : Debug: detail {
Fri Dec 16 12:27:20 2011 : Debug: detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Dec 16 12:27:20 2011 : Debug: header = "%t"
Fri Dec 16 12:27:20 2011 : Debug: detailperm = 384
Fri Dec 16 12:27:20 2011 : Debug: dirperm = 493
Fri Dec 16 12:27:20 2011 : Debug: locking = no
Fri Dec 16 12:27:20 2011 : Debug: log_packet_header = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_unix, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_unix
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "unix" from
file /etc/freeradius/modules/unix
Fri Dec 16 12:27:20 2011 : Debug: unix {
Fri Dec 16 12:27:20 2011 : Debug: radwtmp = "/var/log/freeradius/radwtmp"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: (Loaded rlm_always, checking if it's
valid)
Fri Dec 16 12:27:20 2011 : Debug: Module: Linked to module rlm_always
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module "ok" from
file /etc/freeradius/modules/always
Fri Dec 16 12:27:20 2011 : Debug: always ok {
Fri Dec 16 12:27:20 2011 : Debug: rcode = "ok"
Fri Dec 16 12:27:20 2011 : Debug: simulcount = 0
Fri Dec 16 12:27:20 2011 : Debug: mpp = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module
"attr_filter.accounting_response" from file
/etc/freeradius/modules/attr_filter
Fri Dec 16 12:27:20 2011 : Debug: attr_filter
attr_filter.accounting_response {
Fri Dec 16 12:27:20 2011 : Debug: attrsfile =
"/etc/freeradius/attrs.accounting_response"
Fri Dec 16 12:27:20 2011 : Debug: key = "%{User-Name}"
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking post-proxy {...} for
more modules to load
Fri Dec 16 12:27:20 2011 : Debug: Module: Instantiating module
"post_proxy_log" from file /etc/freeradius/modules/detail.log
Fri Dec 16 12:27:20 2011 : Debug: detail post_proxy_log {
Fri Dec 16 12:27:20 2011 : Debug: detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d"
Fri Dec 16 12:27:20 2011 : Debug: header = "%t"
Fri Dec 16 12:27:20 2011 : Debug: detailperm = 384
Fri Dec 16 12:27:20 2011 : Debug: dirperm = 493
Fri Dec 16 12:27:20 2011 : Debug: locking = no
Fri Dec 16 12:27:20 2011 : Debug: log_packet_header = no
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Module: Checking post-auth {...} for more
modules to load
Fri Dec 16 12:27:20 2011 : Debug: } # modules
Fri Dec 16 12:27:20 2011 : Debug: } # server
Fri Dec 16 12:27:20 2011 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Fri Dec 16 12:27:20 2011 : Debug: listen {
Fri Dec 16 12:27:20 2011 : Debug: type = "auth"
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 10.10.32.35
Fri Dec 16 12:27:20 2011 : Debug: port = 0
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: listen {
Fri Dec 16 12:27:20 2011 : Debug: type = "acct"
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 10.10.32.35
Fri Dec 16 12:27:20 2011 : Debug: port = 0
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: listen {
Fri Dec 16 12:27:20 2011 : Debug: type = "auth"
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 127.0.0.1
Fri Dec 16 12:27:20 2011 : Debug: port = 1812
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: listen {
Fri Dec 16 12:27:20 2011 : Debug: type = "acct"
Fri Dec 16 12:27:20 2011 : Debug: ipaddr = 127.0.0.1
Fri Dec 16 12:27:20 2011 : Debug: port = 1813
Fri Dec 16 12:27:20 2011 : Debug: }
Fri Dec 16 12:27:20 2011 : Debug: Listening on authentication address
10.10.32.35 port 1812
Fri Dec 16 12:27:20 2011 : Debug: Listening on accounting interface eth0
address 10.10.32.35 port 1813
Fri Dec 16 12:27:20 2011 : Debug: Listening on authentication address
127.0.0.1 port 1812 as server inner-tunnel
Fri Dec 16 12:27:20 2011 : Debug: Listening on accounting address 127.0.0.1
port 1813 as server inner-tunnel
Fri Dec 16 12:27:20 2011 : Debug: Listening on proxy address 10.10.32.35
port 1814
Fri Dec 16 12:27:20 2011 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.10.32.22 port 1042, id=17,
length=204
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "edu-teste"
User-Name = "iscte at roam.fccn.pt"
Service-Type = Framed-User
NAS-Port = 253
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-17-f2-e1-1b-95"
Calling-Station-Id = "60-c5-47-8b-ff-46"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
EAP-Message = 0x0207001701697363746540726f616d2e6663636e2e7074
Message-Authenticator = 0x5611cea73ddef4a81a8e8fa85556547b
Fri Dec 16 12:27:21 2011 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Fri Dec 16 12:27:21 2011 : Info: +- entering group authorize {...}
Fri Dec 16 12:27:21 2011 : Info: ++[preprocess] returns ok
Fri Dec 16 12:27:21 2011 : Info: [auth_log] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.10.32.22/auth-detail-20111216
Fri Dec 16 12:27:21 2011 : Info: [auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands
to /var/log/freeradius/radacct/10.10.32.22/auth-detail-20111216
Fri Dec 16 12:27:21 2011 : Info: [auth_log] expand: %t -> Fri Dec 16
12:27:21 2011
Fri Dec 16 12:27:21 2011 : Info: ++[auth_log] returns ok
Fri Dec 16 12:27:21 2011 : Info: ++[request] returns ok
Fri Dec 16 12:27:21 2011 : Info: ++[chap] returns noop
Fri Dec 16 12:27:21 2011 : Info: ++[mschap] returns noop
Fri Dec 16 12:27:21 2011 : Info: [suffix] Looking up realm "roam.fccn.pt"
for User-Name = "iscte at roam.fccn.pt"
Fri Dec 16 12:27:21 2011 : Info: [suffix] Found realm "DEFAULT"
Fri Dec 16 12:27:21 2011 : Info: [suffix] Adding Realm = "DEFAULT"
Fri Dec 16 12:27:21 2011 : Info: [suffix] Proxying request from user iscte
to realm DEFAULT
Fri Dec 16 12:27:21 2011 : Info: [suffix] Preparing to proxy authentication
request to realm "DEFAULT"
Fri Dec 16 12:27:21 2011 : Info: ++[suffix] returns updated
Fri Dec 16 12:27:21 2011 : Info: [eap] Request is supposed to be proxied to
Realm DEFAULT. Not doing EAP.
Fri Dec 16 12:27:21 2011 : Info: ++[eap] returns noop
Fri Dec 16 12:27:21 2011 : Info: [suffix] Request already proxied.
Ignoring.
Fri Dec 16 12:27:21 2011 : Info: ++[suffix] returns ok
Fri Dec 16 12:27:21 2011 : Debug: [ldap] Entering ldap_groupcmp()
Fri Dec 16 12:27:21 2011 : Info: [files] expand:
cn=Users,dc=wiscte,dc=wfarm -> cn=Users,dc=wiscte,dc=wfarm
Fri Dec 16 12:27:21 2011 : Info: [files] expand: %{Stripped-User-Name} ->
Fri Dec 16 12:27:21 2011 : Info: [files] ... expanding second conditional
Fri Dec 16 12:27:21 2011 : Info: [files] expand: %{User-Name} ->
iscte at roam.fccn.pt
Fri Dec 16 12:27:21 2011 : Info: [files] expand:
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(sAMAccountName=iscte at roam.fccn.pt)
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] attempting LDAP reconnection
Fri Dec 16 12:27:21 2011 : Debug: [ldap] (re)connect to 10.10.32.14:389,
authentication 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] bind as CN=Rui Fernando Ferreira
Ribeiro,CN=Users,DC=wiscte,DC=wfarm/xxxxxxx to 10.10.32.14:389
Fri Dec 16 12:27:21 2011 : Debug: [ldap] waiting for bind result ...
Fri Dec 16 12:27:21 2011 : Debug: [ldap] Bind was successful
Fri Dec 16 12:27:21 2011 : Debug: [ldap] performing search in
cn=Users,dc=wiscte,dc=wfarm, with filter (sAMAccountName=iscte at roam.fccn.pt)
Fri Dec 16 12:27:21 2011 : Debug: [ldap] object not found
Fri Dec 16 12:27:21 2011 : Debug: rlm_ldap::ldap_groupcmp: search failed
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] Entering ldap_groupcmp()
Fri Dec 16 12:27:21 2011 : Info: [files] expand:
cn=Users,dc=wiscte,dc=wfarm -> cn=Users,dc=wiscte,dc=wfarm
Fri Dec 16 12:27:21 2011 : Info: [files] expand: %{Stripped-User-Name} ->
Fri Dec 16 12:27:21 2011 : Info: [files] ... expanding second conditional
Fri Dec 16 12:27:21 2011 : Info: [files] expand: %{User-Name} ->
iscte at roam.fccn.pt
Fri Dec 16 12:27:21 2011 : Info: [files] expand:
(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}}) ->
(sAMAccountName=iscte at roam.fccn.pt)
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_get_conn: Got Id: 0
Fri Dec 16 12:27:21 2011 : Debug: [ldap] performing search in
cn=Users,dc=wiscte,dc=wfarm, with filter (sAMAccountName=iscte at roam.fccn.pt)
Fri Dec 16 12:27:21 2011 : Debug: [ldap] object not found
Fri Dec 16 12:27:21 2011 : Debug: rlm_ldap::ldap_groupcmp: search failed
Fri Dec 16 12:27:21 2011 : Debug: [ldap] ldap_release_conn: Release Id: 0
Fri Dec 16 12:27:21 2011 : Info: ++[files] returns noop
Fri Dec 16 12:27:21 2011 : Info: ++[expiration] returns noop
Fri Dec 16 12:27:21 2011 : Info: ++[logintime] returns noop
Fri Dec 16 12:27:21 2011 : Info: ++[pap] returns noop
Fri Dec 16 12:27:21 2011 : Info: WARNING: Empty pre-proxy section. Using
default return values.
Sending Access-Request of id 251 to 10.10.66.18 port 1812
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "edu-teste"
User-Name = "iscte at roam.fccn.pt"
Service-Type = Framed-User
NAS-Port = 253
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-17-f2-e1-1b-95"
Calling-Station-Id = "60-c5-47-8b-ff-46"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
EAP-Message = 0x0207001701697363746540726f616d2e6663636e2e7074
Message-Authenticator = 0x00000000000000000000000000000000
Reply-Message = "Yes"
Proxy-State = 0x3137
Fri Dec 16 12:27:21 2011 : Info: Proxying request 0 to home server
10.10.66.18 port 1812
Sending Access-Request of id 251 to 10.10.66.18 port 1812
Framed-MTU = 1466
NAS-IP-Address = 10.0.1.1
NAS-Identifier = "edu-teste"
User-Name = "iscte at roam.fccn.pt"
Service-Type = Framed-User
NAS-Port = 253
NAS-Port-Type = Ethernet
NAS-Port-Id = "wl0"
Called-Station-Id = "00-17-f2-e1-1b-95"
Calling-Station-Id = "60-c5-47-8b-ff-46"
Connect-Info = "CONNECT Ethernet 54Mbps Half duplex"
EAP-Message = 0x0207001701697363746540726f616d2e6663636e2e7074
Message-Authenticator = 0x00000000000000000000000000000000
Reply-Message = "Yes"
Proxy-State = 0x3137
Fri Dec 16 12:27:21 2011 : Debug: Going to the next request
Fri Dec 16 12:27:21 2011 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Reject packet from host 10.10.66.18 port 1812, id=251,
length=24
Proxy-State = 0x3137
Fri Dec 16 12:27:21 2011 : Info: # Executing section post-proxy from file
/etc/freeradius/sites-enabled/default
Fri Dec 16 12:27:21 2011 : Info: +- entering group post-proxy {...}
Fri Dec 16 12:27:21 2011 : Info: [post_proxy_log] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.10.32.22/post-proxy-detail-20111216
Fri Dec 16 12:27:21 2011 : Info: [post_proxy_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d
expands to
/var/log/freeradius/radacct/10.10.32.22/post-proxy-detail-20111216
Fri Dec 16 12:27:21 2011 : Info: [post_proxy_log] expand: %t -> Fri Dec 16
12:27:21 2011
Fri Dec 16 12:27:21 2011 : Info: ++[post_proxy_log] returns ok
Fri Dec 16 12:27:21 2011 : Info: Using Post-Auth-Type Reject
Fri Dec 16 12:27:21 2011 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Fri Dec 16 12:27:21 2011 : Info: +- entering group REJECT {...}
Fri Dec 16 12:27:21 2011 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> iscte at roam.fccn.pt
Fri Dec 16 12:27:21 2011 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Fri Dec 16 12:27:21 2011 : Info: ++[attr_filter.access_reject] returns
updated
Sending Access-Reject of id 17 to 10.10.32.22 port 1042
Fri Dec 16 12:27:21 2011 : Info: Finished request 0.
Fri Dec 16 12:27:21 2011 : Debug: Going to the next request
Fri Dec 16 12:27:21 2011 : Debug: Waking up in 4.9 seconds.
More information about the Freeradius-Users
mailing list