EAP-TTLS & Kerberos

tod tod at newmexicoconsortium.org
Thu Apr 21 00:56:40 CEST 2011


Hello,
Using the above script I was able to get a clean install to contact my
kerberos server via 'inner-tunnel' and 802.1x.  Unfortunately, Kerberos is
reporting that it needs the User-Password attribute.  I've modified the
script to show that the User-Password is empty in 'inner-tunnel'.  As usual,
the radtest to localhost  works as expected.  eap.conf only has
eap-default-type set to tls, client.conf has the access point loaded, and
'inner-tunnel' is as above, except that if (!User-Password) {...} is added. 
All other files are clean reinstall on centos 5.
Below is the obligatory Debug -X file.

joe Apr 20 14:18:25 2011 : Info: Starting - reading configuration files ...
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/radiusd.conf
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/proxy.conf
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/clients.conf
Wed Apr 20 14:18:25 2011 : Debug: including files in directory
/etc/raddb/modules/
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/checkval
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/perl
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/radutmp
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/smbpasswd
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/inner-eap
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/always
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/sradutmp
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/krb5
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/realm
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/sql_log
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/passwd
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/echo
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/mschap
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/expr
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/pam
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/detail.example.com
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/otp
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/logintime
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/attr_rewrite
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/acct_unique
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/exec
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/unix
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/chap
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/policy
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/counter
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/sqlcounter_expire_on_login
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/detail.log
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/digest
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/files
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/attr_filter
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/ippool
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/pap
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/wimax
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/etc_group
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/linelog
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/cui
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/mac2vlan
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/expiration
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/detail
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/ldap
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/smsotp
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/preprocess
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/modules/mac2ip
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/eap.conf
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/policy.conf
Wed Apr 20 14:18:25 2011 : Debug: including files in directory
/etc/raddb/sites-enabled/
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/sites-enabled/default
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/sites-enabled/inner-tunnel
Wed Apr 20 14:18:25 2011 : Debug: including configuration file
/etc/raddb/sites-enabled/control-socket
Wed Apr 20 14:18:25 2011 : Debug: group = radiusd
Wed Apr 20 14:18:25 2011 : Debug: user = radiusd
Wed Apr 20 14:18:25 2011 : Debug: including dictionary file
/etc/raddb/dictionary
Wed Apr 20 14:18:25 2011 : Debug: main {
Wed Apr 20 14:18:25 2011 : Debug: 	prefix = "/usr"
Wed Apr 20 14:18:25 2011 : Debug: 	localstatedir = "/var"
Wed Apr 20 14:18:25 2011 : Debug: 	logdir = "/var/log/radius"
Wed Apr 20 14:18:25 2011 : Debug: 	libdir = "/usr/lib64/freeradius"
Wed Apr 20 14:18:25 2011 : Debug: 	radacctdir = "/var/log/radius/radacct"
Wed Apr 20 14:18:25 2011 : Debug: 	hostname_lookups = no
Wed Apr 20 14:18:25 2011 : Debug: 	max_request_time = 30
Wed Apr 20 14:18:25 2011 : Debug: 	cleanup_delay = 5
Wed Apr 20 14:18:25 2011 : Debug: 	max_requests = 1024
Wed Apr 20 14:18:25 2011 : Debug: 	allow_core_dumps = no
Wed Apr 20 14:18:25 2011 : Debug: 	pidfile = "/var/run/radiusd/radiusd.pid"
Wed Apr 20 14:18:25 2011 : Debug: 	checkrad = "/usr/sbin/checkrad"
Wed Apr 20 14:18:25 2011 : Debug: 	debug_level = 0
Wed Apr 20 14:18:25 2011 : Debug: 	proxy_requests = yes
Wed Apr 20 14:18:25 2011 : Debug:  log {
Wed Apr 20 14:18:25 2011 : Debug: 	stripped_names = no
Wed Apr 20 14:18:25 2011 : Debug: 	auth = no
Wed Apr 20 14:18:25 2011 : Debug: 	auth_badpass = no
Wed Apr 20 14:18:25 2011 : Debug: 	auth_goodpass = no
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  security {
Wed Apr 20 14:18:25 2011 : Debug: 	max_attributes = 200
Wed Apr 20 14:18:25 2011 : Debug: 	reject_delay = 1
Wed Apr 20 14:18:25 2011 : Debug: 	status_server = yes
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug: }
Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Realms and Home
Servers ####
Wed Apr 20 14:18:25 2011 : Debug:  proxy server {
Wed Apr 20 14:18:25 2011 : Debug: 	retry_delay = 5
Wed Apr 20 14:18:25 2011 : Debug: 	retry_count = 3
Wed Apr 20 14:18:25 2011 : Debug: 	default_fallback = no
Wed Apr 20 14:18:25 2011 : Debug: 	dead_time = 120
Wed Apr 20 14:18:25 2011 : Debug: 	wake_all_if_all_dead = no
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  home_server localhost {
Wed Apr 20 14:18:25 2011 : Debug: 	ipaddr = 127.0.0.1
Wed Apr 20 14:18:25 2011 : Debug: 	port = 1812
Wed Apr 20 14:18:25 2011 : Debug: 	type = "auth"
Wed Apr 20 14:18:25 2011 : Debug: 	secret = "testing123"
Wed Apr 20 14:18:25 2011 : Debug: 	response_window = 20
Wed Apr 20 14:18:25 2011 : Debug: 	max_outstanding = 65536
Wed Apr 20 14:18:25 2011 : Debug: 	require_message_authenticator = no
Wed Apr 20 14:18:25 2011 : Debug: 	zombie_period = 40
Wed Apr 20 14:18:25 2011 : Debug: 	status_check = "status-server"
Wed Apr 20 14:18:25 2011 : Debug: 	ping_interval = 30
Wed Apr 20 14:18:25 2011 : Debug: 	check_interval = 30
Wed Apr 20 14:18:25 2011 : Debug: 	num_answers_to_alive = 3
Wed Apr 20 14:18:25 2011 : Debug: 	num_pings_to_alive = 3
Wed Apr 20 14:18:25 2011 : Debug: 	revive_interval = 120
Wed Apr 20 14:18:25 2011 : Debug: 	status_check_timeout = 4
Wed Apr 20 14:18:25 2011 : Debug: 	irt = 2
Wed Apr 20 14:18:25 2011 : Debug: 	mrt = 16
Wed Apr 20 14:18:25 2011 : Debug: 	mrc = 5
Wed Apr 20 14:18:25 2011 : Debug: 	mrd = 30
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  home_server_pool my_auth_failover {
Wed Apr 20 14:18:25 2011 : Debug: 	type = fail-over
Wed Apr 20 14:18:25 2011 : Debug: 	home_server = localhost
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  realm example.com {
Wed Apr 20 14:18:25 2011 : Debug: 	auth_pool = my_auth_failover
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  realm LOCAL {
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Clients ####
Wed Apr 20 14:18:25 2011 : Debug:  client localhost {
Wed Apr 20 14:18:25 2011 : Debug: 	ipaddr = 127.0.0.1
Wed Apr 20 14:18:25 2011 : Debug: 	require_message_authenticator = no
Wed Apr 20 14:18:25 2011 : Debug: 	secret = "testing123"
Wed Apr 20 14:18:25 2011 : Debug: 	nastype = "other"
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug:  client AccessPoint {
Wed Apr 20 14:18:25 2011 : Debug: 	ipaddr = 10.x.x.x
Wed Apr 20 14:18:25 2011 : Debug: 	require_message_authenticator = no
Wed Apr 20 14:18:25 2011 : Debug: 	secret = "newmexicoconsortium"
Wed Apr 20 14:18:25 2011 : Debug: 	shortname = "NMCproBe"
Wed Apr 20 14:18:25 2011 : Debug: 	nastype = "other"
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Instantiating modules ####
Wed Apr 20 14:18:25 2011 : Debug:  instantiate {
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_exec, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_exec
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating exec
Wed Apr 20 14:18:25 2011 : Debug:   exec {
Wed Apr 20 14:18:25 2011 : Debug: 	wait = no
Wed Apr 20 14:18:25 2011 : Debug: 	input_pairs = "request"
Wed Apr 20 14:18:25 2011 : Debug: 	shell_escape = yes
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_expr, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_expr
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating expr
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_expiration, checking if
it's valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_expiration
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating expiration
Wed Apr 20 14:18:25 2011 : Debug:   expiration {
Wed Apr 20 14:18:25 2011 : Debug: 	reply-message = "Password Has Expired  "
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_logintime, checking if
it's valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_logintime
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating logintime
Wed Apr 20 14:18:25 2011 : Debug:   logintime {
Wed Apr 20 14:18:25 2011 : Debug: 	reply-message = "You are calling outside
your allowed timespan  "
Wed Apr 20 14:18:25 2011 : Debug: 	minimum-timeout = 60
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Loading Virtual Servers ####
Wed Apr 20 14:18:25 2011 : Debug: server inner-tunnel {
Wed Apr 20 14:18:25 2011 : Debug:  modules {
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking authenticate {...} for
more modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_pap, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_pap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating pap
Wed Apr 20 14:18:25 2011 : Debug:   pap {
Wed Apr 20 14:18:25 2011 : Debug: 	encryption_scheme = "auto"
Wed Apr 20 14:18:25 2011 : Debug: 	auto_header = no
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_krb5, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_krb5
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating krb5
Wed Apr 20 14:18:25 2011 : Debug:   krb5 {
Wed Apr 20 14:18:25 2011 : Debug: 	keytab = "/path/to/keytab"
Wed Apr 20 14:18:25 2011 : Debug: 	service_principal = "name_of_principle"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Auth: rlm_krb5: krb5_init ok
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking authorize {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking session {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_radutmp, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_radutmp
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating radutmp
Wed Apr 20 14:18:25 2011 : Debug:   radutmp {
Wed Apr 20 14:18:25 2011 : Debug: 	filename = "/var/log/radius/radutmp"
Wed Apr 20 14:18:25 2011 : Debug: 	username = "%{User-Name}"
Wed Apr 20 14:18:25 2011 : Debug: 	case_sensitive = yes
Wed Apr 20 14:18:25 2011 : Debug: 	check_with_nas = yes
Wed Apr 20 14:18:25 2011 : Debug: 	perm = 384
Wed Apr 20 14:18:25 2011 : Debug: 	callerid = yes
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_eap, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_eap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap
Wed Apr 20 14:18:25 2011 : Debug:   eap {
Wed Apr 20 14:18:25 2011 : Debug: 	default_eap_type = "tls"
Wed Apr 20 14:18:25 2011 : Debug: 	timer_expire = 60
Wed Apr 20 14:18:25 2011 : Debug: 	ignore_unknown_eap_types = no
Wed Apr 20 14:18:25 2011 : Debug: 	cisco_accounting_username_bug = no
Wed Apr 20 14:18:25 2011 : Debug: 	max_sessions = 2048
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_md5
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-md5
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_leap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-leap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-gtc
Wed Apr 20 14:18:25 2011 : Debug:    gtc {
Wed Apr 20 14:18:25 2011 : Debug: 	challenge = "Password: "
Wed Apr 20 14:18:25 2011 : Debug: 	auth_type = "PAP"
Wed Apr 20 14:18:25 2011 : Debug:    }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_tls
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-tls
Wed Apr 20 14:18:25 2011 : Debug:    tls {
Wed Apr 20 14:18:25 2011 : Debug: 	rsa_key_exchange = no
Wed Apr 20 14:18:25 2011 : Debug: 	dh_key_exchange = yes
Wed Apr 20 14:18:25 2011 : Debug: 	rsa_key_length = 512
Wed Apr 20 14:18:25 2011 : Debug: 	dh_key_length = 512
Wed Apr 20 14:18:25 2011 : Debug: 	verify_depth = 0
Wed Apr 20 14:18:25 2011 : Debug: 	pem_file_type = yes
Wed Apr 20 14:18:25 2011 : Debug: 	private_key_file =
"/etc/raddb/certs/server.pem"
Wed Apr 20 14:18:25 2011 : Debug: 	certificate_file =
"/etc/raddb/certs/server.pem"
Wed Apr 20 14:18:25 2011 : Debug: 	CA_file = "/etc/raddb/certs/ca.pem"
Wed Apr 20 14:18:25 2011 : Debug: 	private_key_password = "whatever"
Wed Apr 20 14:18:25 2011 : Debug: 	dh_file = "/etc/raddb/certs/dh"
Wed Apr 20 14:18:25 2011 : Debug: 	random_file = "/etc/raddb/certs/random"
Wed Apr 20 14:18:25 2011 : Debug: 	fragment_size = 1024
Wed Apr 20 14:18:25 2011 : Debug: 	include_length = yes
Wed Apr 20 14:18:25 2011 : Debug: 	check_crl = no
Wed Apr 20 14:18:25 2011 : Debug: 	cipher_list = "DEFAULT"
Wed Apr 20 14:18:25 2011 : Debug: 	make_cert_command =
"/etc/raddb/certs/bootstrap"
Wed Apr 20 14:18:25 2011 : Debug:     cache {
Wed Apr 20 14:18:25 2011 : Debug: 	enable = no
Wed Apr 20 14:18:25 2011 : Debug: 	lifetime = 24
Wed Apr 20 14:18:25 2011 : Debug: 	max_entries = 255
Wed Apr 20 14:18:25 2011 : Debug:     }
Wed Apr 20 14:18:25 2011 : Debug:    }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-ttls
Wed Apr 20 14:18:25 2011 : Debug:    ttls {
Wed Apr 20 14:18:25 2011 : Debug: 	default_eap_type = "tls"
Wed Apr 20 14:18:25 2011 : Debug: 	copy_request_to_tunnel = no
Wed Apr 20 14:18:25 2011 : Debug: 	use_tunneled_reply = no
Wed Apr 20 14:18:25 2011 : Debug: 	virtual_server = "inner-tunnel"
Wed Apr 20 14:18:25 2011 : Debug: 	include_length = yes
Wed Apr 20 14:18:25 2011 : Debug:    }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module rlm_eap_peap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-peap
Wed Apr 20 14:18:25 2011 : Debug:    peap {
Wed Apr 20 14:18:25 2011 : Debug: 	default_eap_type = "mschapv2"
Wed Apr 20 14:18:25 2011 : Debug: 	copy_request_to_tunnel = no
Wed Apr 20 14:18:25 2011 : Debug: 	use_tunneled_reply = no
Wed Apr 20 14:18:25 2011 : Debug: 	proxy_tunneled_request_as_eap = yes
Wed Apr 20 14:18:25 2011 : Debug: 	virtual_server = "inner-tunnel"
Wed Apr 20 14:18:25 2011 : Debug:    }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to sub-module
rlm_eap_mschapv2
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating eap-mschapv2
Wed Apr 20 14:18:25 2011 : Debug:    mschapv2 {
Wed Apr 20 14:18:25 2011 : Debug: 	with_ntdomain_hack = no
Wed Apr 20 14:18:25 2011 : Debug:    }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking post-auth {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_attr_filter, checking if
it's valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_attr_filter
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating
attr_filter.access_reject
Wed Apr 20 14:18:25 2011 : Debug:   attr_filter attr_filter.access_reject {
Wed Apr 20 14:18:25 2011 : Debug: 	attrsfile =
"/etc/raddb/attrs.access_reject"
Wed Apr 20 14:18:25 2011 : Debug: 	key = "%{User-Name}"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  } # modules
Wed Apr 20 14:18:25 2011 : Debug: } # server
Wed Apr 20 14:18:25 2011 : Debug: server {
Wed Apr 20 14:18:25 2011 : Debug:  modules {
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking authenticate {...} for
more modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_chap, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_chap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating chap
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_mschap, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_mschap
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating mschap
Wed Apr 20 14:18:25 2011 : Debug:   mschap {
Wed Apr 20 14:18:25 2011 : Debug: 	use_mppe = yes
Wed Apr 20 14:18:25 2011 : Debug: 	require_encryption = no
Wed Apr 20 14:18:25 2011 : Debug: 	require_strong = no
Wed Apr 20 14:18:25 2011 : Debug: 	with_ntdomain_hack = no
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_unix, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_unix
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating unix
Wed Apr 20 14:18:25 2011 : Debug:   unix {
Wed Apr 20 14:18:25 2011 : Debug: 	radwtmp = "/var/log/radius/radwtmp"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking authorize {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_preprocess, checking if
it's valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_preprocess
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating preprocess
Wed Apr 20 14:18:25 2011 : Debug:   preprocess {
Wed Apr 20 14:18:25 2011 : Debug: 	huntgroups = "/etc/raddb/huntgroups"
Wed Apr 20 14:18:25 2011 : Debug: 	hints = "/etc/raddb/hints"
Wed Apr 20 14:18:25 2011 : Debug: 	with_ascend_hack = no
Wed Apr 20 14:18:25 2011 : Debug: 	ascend_channels_per_line = 23
Wed Apr 20 14:18:25 2011 : Debug: 	with_ntdomain_hack = no
Wed Apr 20 14:18:25 2011 : Debug: 	with_specialix_jetstream_hack = no
Wed Apr 20 14:18:25 2011 : Debug: 	with_cisco_vsa_hack = no
Wed Apr 20 14:18:25 2011 : Debug: 	with_alvarion_vsa_hack = no
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_realm, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_realm
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating suffix
Wed Apr 20 14:18:25 2011 : Debug:   realm suffix {
Wed Apr 20 14:18:25 2011 : Debug: 	format = "suffix"
Wed Apr 20 14:18:25 2011 : Debug: 	delimiter = "@"
Wed Apr 20 14:18:25 2011 : Debug: 	ignore_default = no
Wed Apr 20 14:18:25 2011 : Debug: 	ignore_null = no
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_files, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_files
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating files
Wed Apr 20 14:18:25 2011 : Debug:   files {
Wed Apr 20 14:18:25 2011 : Debug: 	usersfile = "/etc/raddb/users"
Wed Apr 20 14:18:25 2011 : Debug: 	acctusersfile = "/etc/raddb/acct_users"
Wed Apr 20 14:18:25 2011 : Debug: 	preproxy_usersfile =
"/etc/raddb/preproxy_users"
Wed Apr 20 14:18:25 2011 : Debug: 	compat = "no"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking preacct {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_acct_unique, checking if
it's valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_acct_unique
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating acct_unique
Wed Apr 20 14:18:25 2011 : Debug:   acct_unique {
Wed Apr 20 14:18:25 2011 : Debug: 	key = "User-Name, Acct-Session-Id,
NAS-IP-Address, Client-IP-Address, NAS-Port"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking accounting {...} for
more modules to load
Wed Apr 20 14:18:25 2011 : Debug:     (Loaded rlm_detail, checking if it's
valid)
Wed Apr 20 14:18:25 2011 : Debug:  Module: Linked to module rlm_detail
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating detail
Wed Apr 20 14:18:25 2011 : Debug:   detail {
Wed Apr 20 14:18:25 2011 : Debug: 	detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Wed Apr 20 14:18:25 2011 : Debug: 	header = "%t"
Wed Apr 20 14:18:25 2011 : Debug: 	detailperm = 384
Wed Apr 20 14:18:25 2011 : Debug: 	dirperm = 493
Wed Apr 20 14:18:25 2011 : Debug: 	locking = no
Wed Apr 20 14:18:25 2011 : Debug: 	log_packet_header = no
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Instantiating
attr_filter.accounting_response
Wed Apr 20 14:18:25 2011 : Debug:   attr_filter
attr_filter.accounting_response {
Wed Apr 20 14:18:25 2011 : Debug: 	attrsfile =
"/etc/raddb/attrs.accounting_response"
Wed Apr 20 14:18:25 2011 : Debug: 	key = "%{User-Name}"
Wed Apr 20 14:18:25 2011 : Debug:   }
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking session {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking post-proxy {...} for
more modules to load
Wed Apr 20 14:18:25 2011 : Debug:  Module: Checking post-auth {...} for more
modules to load
Wed Apr 20 14:18:25 2011 : Debug:  } # modules
Wed Apr 20 14:18:25 2011 : Debug: } # server
Wed Apr 20 14:18:25 2011 : Debug: radiusd: #### Opening IP addresses and
Ports ####
Wed Apr 20 14:18:25 2011 : Debug: listen {
Wed Apr 20 14:18:25 2011 : Debug: 	type = "auth"
Wed Apr 20 14:18:25 2011 : Debug: 	ipaddr = *
Wed Apr 20 14:18:25 2011 : Debug: 	port = 0
Wed Apr 20 14:18:25 2011 : Debug: }
Wed Apr 20 14:18:25 2011 : Debug: listen {
Wed Apr 20 14:18:25 2011 : Debug: 	type = "acct"
Wed Apr 20 14:18:25 2011 : Debug: 	ipaddr = *
Wed Apr 20 14:18:25 2011 : Debug: 	port = 0
Wed Apr 20 14:18:25 2011 : Debug: }
Wed Apr 20 14:18:25 2011 : Debug: listen {
Wed Apr 20 14:18:25 2011 : Debug: 	type = "control"
Wed Apr 20 14:18:25 2011 : Debug:  listen {
Wed Apr 20 14:18:25 2011 : Debug: 	socket = "/var/run/radiusd/radiusd.sock"
Wed Apr 20 14:18:25 2011 : Debug:  }
Wed Apr 20 14:18:25 2011 : Debug: }
Wed Apr 20 14:18:25 2011 : Debug: Listening on authentication address * port
1812
Wed Apr 20 14:18:25 2011 : Debug: Listening on accounting address * port
1813
Wed Apr 20 14:18:25 2011 : Debug: Listening on command file
/var/run/radiusd/radiusd.sock
Wed Apr 20 14:18:25 2011 : Debug: Listening on proxy address * port 1814
Wed Apr 20 14:18:25 2011 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=123
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x0200000a01746f747465
	Message-Authenticator = 0x89ac236886e773c0c4d5ab2a8a8c3289
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 0 length
10
Wed Apr 20 14:19:28 2011 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns updated
Wed Apr 20 14:19:28 2011 : Info: ++[unix] returns notfound
Wed Apr 20 14:19:28 2011 : Info: [files] users: Matched entry DEFAULT at
line 204
Wed Apr 20 14:19:28 2011 : Info: ++[files] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop
Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP Identity
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type tls
Wed Apr 20 14:19:28 2011 : Info: [tls] Requiring client certificate
Wed Apr 20 14:19:28 2011 : Info: [tls] Initiate
Wed Apr 20 14:19:28 2011 : Info: [tls] Start returned 1
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message = 0x010100060d20
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bdd11510762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 0.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=137
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 0 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bdd11510762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020100060319
	Message-Authenticator = 0xba61fba10d6a196c3808ac451c9b8057
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 1 length
6
Wed Apr 20 14:19:28 2011 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns updated
Wed Apr 20 14:19:28 2011 : Info: ++[unix] returns notfound
Wed Apr 20 14:19:28 2011 : Info: [files] users: Matched entry DEFAULT at
line 204
Wed Apr 20 14:19:28 2011 : Info: ++[files] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop
Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP NAK
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP-NAK asked for EAP-Type/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type tls
Wed Apr 20 14:19:28 2011 : Info: [tls] Initiate
Wed Apr 20 14:19:28 2011 : Info: [tls] Start returned 1
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message = 0x010200061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bdc12450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 1.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=295
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 1 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bdc12450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message =
0x020200a419800000009a16030100950100009103014daf3fd25dbaeecc6fd0481aaaa97bc6550d4f8410305d48510dbd68d00d1090000056c00ac009c007c008c013c014c011c012c004c005c002c003c00ec00fc00cc00d002f000500040035000a000900030008000600320033003800390016001500140013001200110034003a0018001b001a00170019000101000012000a00080006001700180019000b00020100
	Message-Authenticator = 0x4047b0bc80d020d772aa38cd5422c8a1
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "10.x.x.x",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 2 length
164
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Debug:   TLS Length 154
Wed Apr 20 14:19:28 2011 : Info: [peap] Length Included
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 11 
Wed Apr 20 14:19:28 2011 : Info: [peap]     (other): before/accept
initialization 
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: before/accept
initialization 
Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0095],
ClientHello  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 read client
hello A 
Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 002a],
ServerHello  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 write server
hello A 
Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 085e],
Certificate  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 write
certificate A 
Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0004],
ServerHelloDone  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 write server
done A 
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 flush data 
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: Need to read more
data: SSLv3 read client certificate A
Wed Apr 20 14:19:28 2011 : Debug: In SSL Handshake Phase 
Wed Apr 20 14:19:28 2011 : Debug: In SSL Accept mode  
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x0103040019c00000089b160301002a0200002603014daf3fd01907bdd33b7d36411279bd6ba34b676bcded0c51aeea9016f4aa62cd00002f00160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479
	EAP-Message =
0x301e170d3131303432303137333433325a170d3132303431393137333433325a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100a66b73a4f0edb13c2ee7a2bad5a7d68480898ea958f7e910d3f98b327ffb99ec22d9ce06f239df8397705fd08f2c224707ac97de482bf2885fdac7203116
	EAP-Message =
0xbe906d4c1b1092ec9953cb80d153cbf3386789605d6e80aefa9c44497fa7df5cc4ac6ed8178fdbedbdddd79b5bc071ba2a001a9978c2eaaeae754c73cacb643cf16d399334b8444df96c39cc0c8294cc9b5fc1902f770c50df7d23b6c29926752facbee3c192c27d1ca74606f34cefadc89dd292a4bf3e95662dc29cfe1fa393a41e8d3491241cc85819a890336bf7f969e44bab85c7034b3ee9c2b435958fc64dcae0dba5e69f288c0f5d767c3684537961b224ea1876859fa66693d56b65f986c70203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010405000382010100baac5a704642dea672
	EAP-Message =
0xf793ebdbf19512f838f5aae9b4d4ac9371e0415ecf6093cf11209e515bfacba06566dfbaf2cb8084e40aa17cb8c91abcf673fc95c0057c67e75e1f063442d484ca598c72843bb45eed25c36971b0c7054d7580505426d72f9e6bde547bac67db3512ec087858cb65bbed3255361ea9de3100a9459c0945cdd499b7e5c46ea1b835d104289557ea43642c1ec4a52bebdcc8ef10425dcb39ee2de7d5cec817f14d9995b870a079e4dacf106dc5396eedabbf45a22e5a9f4eb5463172be5ddd9ba639b634783e8c14f53ea817956bed3e4bac1fdbee818771316949c8667c82358babfaf27fbbd7c65de76cb7a38522e50c11f5b292ca6a180004ab308204
	EAP-Message = 0xa73082038fa0030201020209
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bdf13450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 2.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=137
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 2 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bdf13450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020300061900
	Message-Authenticator = 0x7c035bbf6b241a95d2a22f744a102f03
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 3 length
6
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK
Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake fragment handler
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 1 
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x010403fc194000fdc25082a03098fd300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3131303432303137333433325a170d3132303431393137333433325a308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504
	EAP-Message =
0x071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100ec507dbcc0cf48a24e08bbfecc416c8648719655dd901d023ddbc2ff604819752a21ed64029ed1762d2abbbcbfd6c49702a873ced95144d7b08268b0574cb618e8e9794b16707e8b85ae799cd112b0ac9f06cfaf7d0386f9d8b2fbb46adade8a159dbb92dac84d06247b714c227cd3
	EAP-Message =
0xea3f91ffa26b62886cacacf3d8c87418e3619fd33020e4877ae61d298aa0ab23df2c0eea0012e07228409884f3ab9d256c664a17b5d8352e0e01cce202847b895c2f17b7e7984f069d73c1e36063e85c8a5ea80ee47891e5a67d566e15fa065dc4440baaa89efb371a04193593d1efe062575dece95d2b729ac997309e8b7a964aef029fee7101a37ea13d0eda5c42e76f0203010001a381fb3081f8301d0603551d0e0416041458dc04911e60bdfece1ced5d9ccb591f613a9ea83081c80603551d230481c03081bd801458dc04911e60bdfece1ced5d9ccb591f613a9ea8a18199a48196308193310b3009060355040613024652310f300d06035504
	EAP-Message =
0x0813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479820900fdc25082a03098fd300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100a6d09c3a6e5bfb70fbe4728ded653e3db77e8bd53eae3b2233477c0c78c5b8969d77416542a500a7b412058cd5d06d546839489c67c94327ecb68f85ae7d69284b6efc9f6bc06d22a1e9c48a903f28fb9988
	EAP-Message = 0xc1bd1cf2f83eb432
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bde14450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 3.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=137
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 3 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bde14450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020400061900
	Message-Authenticator = 0x53ed16f1e518e85e03755d94da317033
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 4 length
6
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK
Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake fragment handler
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 1 
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x010500b519002f4b578c9cb29c7e4c4efd654179aa8af5133ec300b56bcb0d962423eb357efb49a3242bb5c70bc9359a8a49456d6f2c8543e645247e8fc58336f1a796ee1f59d1591268e348b8688cf978a48541ce50f715f173d935a3e9a611414ff670717c45c29f002ef8ecd5cd987a315d3da307f4ee9e5b252411234b6414a4ebb99b8bc933e85af7cebcc83ff11febd4d881dbdb02f604620321fdbee10dccf0c6d53a40606759f92e16030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bd915450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 4.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=469
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 4 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bd915450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message =
0x0205015019800000014616030101061000010201005ff03a87a0137ac0ad3d30d889be6290d586fe4f8774d04a281fce89ab478bd7ca78d17dd10bf634210465ea16900c200895a7e5bf72bac2ec49a0d58dc73c6f73f0a7f9f7d7d3126e2cd36d4abdcc9d11d8511eb7e181213e05c79d2f412ee87b5466b45d4f8fc7fd4dda6823a5e05ab80b2b1c99d949cfffade2ffe14b383d8df00a2e0a7f29b0102231bb942e6850f815f062183512ec5cf29a25af967190a443038bbecaa71936c7f2b23ee815c2bc41aa4ba1e1bbead97f03fc0de3817564be247b6a7af8529f5d2f2833ea01d902c760be8c4380a7ea758ad8eee9ab6bd9117e4494431b40
	EAP-Message =
0xdab05b2e027376bbd9c7d336e111eb765e75c65080c4d6571403010001011603010030de7128d079ec3a74a608b7ad34a52e70200bc5524ff54d6a3c265f1a8d9de489ce6ce763f2fb3c7afcd22959cb4e5dfd
	Message-Authenticator = 0xd728400175580c5a526116bf2f1b1a8f
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 5 length
253
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Debug:   TLS Length 326
Wed Apr 20 14:19:28 2011 : Info: [peap] Length Included
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 11 
Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0106],
ClientKeyExchange  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 read client
key exchange A 
Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 ChangeCipherSpec [length
0001]  
Wed Apr 20 14:19:28 2011 : Info: [peap] <<< TLS 1.0 Handshake [length 0010],
Finished  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 read finished
A 
Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 ChangeCipherSpec [length
0001]  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 write change
cipher spec A 
Wed Apr 20 14:19:28 2011 : Info: [peap] >>> TLS 1.0 Handshake [length 0010],
Finished  
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 write finished
A 
Wed Apr 20 14:19:28 2011 : Info: [peap]     TLS_accept: SSLv3 flush data 
Wed Apr 20 14:19:28 2011 : Info: [peap]     (other): SSL negotiation
finished successfully 
Wed Apr 20 14:19:28 2011 : Debug: SSL Connection Established 
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 13 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_HANDLED
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x0106004119001403010001011603010030099c636cd573aaf67853ce908c03124c44da0b7887fdbfc4fb7dcf77fce218a6a0a94a3fef781df5632cb80eb8e5370f
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bd816450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 5.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=137
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 5 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bd816450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020600061900
	Message-Authenticator = 0x8f1642e15961150878f41f38f1df7fec
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 6 length
6
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Info: [peap] Received TLS ACK
Wed Apr 20 14:19:28 2011 : Info: [peap] ACK handshake is finished
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 3 
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 3 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_SUCCESS
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x0107002b190017030100203cb1c1276777a2a1f4f1fe7625e0dc14beeac2811bd82eb05b38147ee4ba34c7
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bdb17450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 6.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=174
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 6 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bdb17450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message =
0x0207002b19001703010020d3d2a3f046f09cdd567ad9cd3626c14e1e136ddba422e9a81f4fab0b70acf4c0
	Message-Authenticator = 0xd882a36ea1058c0dac06f385abebdaab
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 7 length
43
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 7 
Wed Apr 20 14:19:28 2011 : Info: [peap] Done initial handshake
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 7 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_OK
Wed Apr 20 14:19:28 2011 : Info: [peap] Session established.  Decoding
tunneled attributes.
Wed Apr 20 14:19:28 2011 : Info: [peap] Identity - joe
Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled request
	EAP-Message = 0x0207000a01746f747465
server  {
Wed Apr 20 14:19:28 2011 : Debug:   PEAP: Got tunneled identity of joe
Wed Apr 20 14:19:28 2011 : Debug:   PEAP: Setting default EAP type for
tunneled EAP session.
Wed Apr 20 14:19:28 2011 : Debug:   PEAP: Setting User-Name to joe
Sending tunneled request
	EAP-Message = 0x0207000a01746f747465
	FreeRADIUS-Proxied-To = 127.0.0.1
	User-Name = "joe"
server inner-tunnel {
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[expiration] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[logintime] returns noop
Wed Apr 20 14:19:28 2011 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Wed Apr 20 14:19:28 2011 : Info: ++[pap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password)
Wed Apr 20 14:19:28 2011 : Info: ? Evaluating (User-Password) -> FALSE
Wed Apr 20 14:19:28 2011 : Info: ++? if (User-Password) -> FALSE
Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password)
Wed Apr 20 14:19:28 2011 : Info: ? Evaluating !(User-Password) -> TRUE
Wed Apr 20 14:19:28 2011 : Info: ++? if (!User-Password) -> TRUE
Wed Apr 20 14:19:28 2011 : Info: ++- entering if (!User-Password) {...}
Wed Apr 20 14:19:28 2011 : Info: +++[control] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++- if (!User-Password) returns noop
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = Kerberos
Wed Apr 20 14:19:28 2011 : Info: +- entering group Kerberos {...}
Wed Apr 20 14:19:28 2011 : Auth: rlm_krb5: Attribute "User-Password" is
required for authentication.
Wed Apr 20 14:19:28 2011 : Info: ++[krb5] returns invalid
Wed Apr 20 14:19:28 2011 : Info: Failed to authenticate the user.
} # server inner-tunnel
Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled reply code 3
Wed Apr 20 14:19:28 2011 : Info: [peap] Got tunneled reply RADIUS code 3
Wed Apr 20 14:19:28 2011 : Info: [peap] Tunneled authentication was
rejected.
Wed Apr 20 14:19:28 2011 : Info: [peap] FAILURE
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.x.x.x port 2099
	EAP-Message =
0x0108002b19001703010020da58f6451bae89da36c894c1c6b16c6895257d7c354dfa0eb09a833a0fa3768b
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xdd105c2bda18450762e93958e0c3f1d3
Wed Apr 20 14:19:28 2011 : Info: Finished request 7.
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.x.x.x port 2099, id=0,
length=174
Wed Apr 20 14:19:28 2011 : Info: Cleaning up request 7 ID 0 with timestamp
+63
	User-Name = "joe"
	NAS-IP-Address = 10.x.x.x
	Called-Station-Id = "021c104128f3"
	Calling-Station-Id = "78ca39bc0256"
	NAS-Identifier = "021c104128f3"
	NAS-Port = 40
	Framed-MTU = 1400
	State = 0xdd105c2bda18450762e93958e0c3f1d3
	NAS-Port-Type = Wireless-802.11
	EAP-Message =
0x0208002b19001703010020c1754eafe7cea50b9cfb512e9d7f44e826d21d5b3405a9a3d56ff6f95ff424de
	Message-Authenticator = 0x16184e6807f8406dd2a6454fe102d325
Wed Apr 20 14:19:28 2011 : Info: +- entering group authorize {...}
Wed Apr 20 14:19:28 2011 : Info: ++[preprocess] returns ok
Wed Apr 20 14:19:28 2011 : Info: ++[chap] returns noop
Wed Apr 20 14:19:28 2011 : Info: ++[mschap] returns noop
Wed Apr 20 14:19:28 2011 : Info: [suffix] No '@' in User-Name = "joe",
looking up realm NULL
Wed Apr 20 14:19:28 2011 : Info: [suffix] No such realm "NULL"
Wed Apr 20 14:19:28 2011 : Info: ++[suffix] returns noop
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP packet type response id 8 length
43
Wed Apr 20 14:19:28 2011 : Info: [eap] Continuing tunnel setup.
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns ok
Wed Apr 20 14:19:28 2011 : Info: Found Auth-Type = EAP
Wed Apr 20 14:19:28 2011 : Info: +- entering group authenticate {...}
Wed Apr 20 14:19:28 2011 : Info: [eap] Request found, released from the list
Wed Apr 20 14:19:28 2011 : Info: [eap] EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] processing type peap
Wed Apr 20 14:19:28 2011 : Info: [peap] processing EAP-TLS
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_verify returned 7 
Wed Apr 20 14:19:28 2011 : Info: [peap] Done initial handshake
Wed Apr 20 14:19:28 2011 : Info: [peap] eaptls_process returned 7 
Wed Apr 20 14:19:28 2011 : Info: [peap] EAPTLS_OK
Wed Apr 20 14:19:28 2011 : Info: [peap] Session established.  Decoding
tunneled attributes.
Wed Apr 20 14:19:28 2011 : Info: [peap] Received EAP-TLV response.
Wed Apr 20 14:19:28 2011 : Info: [peap]  Had sent TLV failure.  User was
rejected earlier in this session.
Wed Apr 20 14:19:28 2011 : Info: [eap] Handler failed in EAP/peap
Wed Apr 20 14:19:28 2011 : Info: [eap] Failed in EAP select
Wed Apr 20 14:19:28 2011 : Info: ++[eap] returns invalid
Wed Apr 20 14:19:28 2011 : Info: Failed to authenticate the user.
Wed Apr 20 14:19:28 2011 : Info: Using Post-Auth-Type Reject
Wed Apr 20 14:19:28 2011 : Info: +- entering group REJECT {...}
Wed Apr 20 14:19:28 2011 : Info: [attr_filter.access_reject] 	expand:
%{User-Name} -> joe
Wed Apr 20 14:19:28 2011 : Debug:  attr_filter: Matched entry DEFAULT at
line 11
Wed Apr 20 14:19:28 2011 : Info: ++[attr_filter.access_reject] returns
updated
Wed Apr 20 14:19:28 2011 : Info: Delaying reject of request 8 for 1 seconds
Wed Apr 20 14:19:28 2011 : Debug: Going to the next request
Wed Apr 20 14:19:28 2011 : Debug: Waking up in 0.9 seconds.
Wed Apr 20 14:19:29 2011 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 0 to 10.x.x.x port 2099
	EAP-Message = 0x04080004
	Message-Authenticator = 0x00000000000000000000000000000000
Wed Apr 20 14:19:29 2011 : Debug: Waking up in 4.9 seconds.
Wed Apr 20 14:19:34 2011 : Info: Cleaning up request 8 ID 0 with timestamp
+63
Wed Apr 20 14:19:34 2011 : Debug: Ready to process requests.
  

--
View this message in context: http://freeradius.1045715.n5.nabble.com/EAP-TTLS-Kerberos-tp3368060p4329503.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.



More information about the Freeradius-Users mailing list