Tue Dec 17 17:11:55 2013 : Info: FreeRADIUS Version 2.1.12, for host x86_64-redhat-linux-gnu, built on Oct  3 2012 at 01:22:51
Tue Dec 17 17:11:55 2013 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. 
Tue Dec 17 17:11:55 2013 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
Tue Dec 17 17:11:55 2013 : Info: PARTICULAR PURPOSE. 
Tue Dec 17 17:11:55 2013 : Info: You may redistribute copies of FreeRADIUS under the terms of the 
Tue Dec 17 17:11:55 2013 : Info: GNU General Public License v2. 
Tue Dec 17 17:11:55 2013 : Info: Starting - reading configuration files ...
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/radiusd.conf
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/proxy.conf
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/clients.conf
Tue Dec 17 17:11:55 2013 : Debug: including files in directory /etc/raddb/modules/
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/opendirectory
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/soh
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/ippool
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/policy
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/digest
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/acct_unique
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/checkval
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/chap
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/ntlm_auth
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/unix
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/dynamic_clients
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/mac2ip
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/exec
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/preprocess
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/mschap.backup
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/pap
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/smsotp
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/smbpasswd
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/expr
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/krb5
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/mschap
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/inner-eap
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/detail
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/attr_filter
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/expiration
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/pam
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/cui
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/always
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/passwd
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/counter
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/redis
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/radutmp
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/detail.example.com
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/sradutmp
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/perl
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/replicate
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/linelog
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/detail.log
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/ldap
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/logintime
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/realm
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/sql_log
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/rediswho
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/echo
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/otp
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/wimax
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/etc_group
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/mac2vlan
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/files
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/modules/attr_rewrite
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/eap.conf
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/sql.conf
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/sql/mysql/dialup.conf
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/policy.conf
Tue Dec 17 17:11:55 2013 : Debug: including files in directory /etc/raddb/sites-enabled/
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/sites-enabled/control-socket
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/sites-enabled/inner-tunnel
Tue Dec 17 17:11:55 2013 : Debug: including configuration file /etc/raddb/sites-enabled/default
Tue Dec 17 17:11:55 2013 : Debug: main {
Tue Dec 17 17:11:55 2013 : Debug: 	user = "radiusd"
Tue Dec 17 17:11:55 2013 : Debug: 	group = "radiusd"
Tue Dec 17 17:11:55 2013 : Debug: 	allow_core_dumps = no
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Debug: including dictionary file /etc/raddb/dictionary
Tue Dec 17 17:11:55 2013 : Debug: main {
Tue Dec 17 17:11:55 2013 : Debug: 	name = "radiusd"
Tue Dec 17 17:11:55 2013 : Debug: 	prefix = "/usr"
Tue Dec 17 17:11:55 2013 : Debug: 	localstatedir = "/var"
Tue Dec 17 17:11:55 2013 : Debug: 	sbindir = "/usr/sbin"
Tue Dec 17 17:11:55 2013 : Debug: 	logdir = "/var/log/radius"
Tue Dec 17 17:11:55 2013 : Debug: 	run_dir = "/var/run/radiusd"
Tue Dec 17 17:11:55 2013 : Debug: 	libdir = "/usr/lib64/freeradius"
Tue Dec 17 17:11:55 2013 : Debug: 	radacctdir = "/var/log/radius/radacct"
Tue Dec 17 17:11:55 2013 : Debug: 	hostname_lookups = no
Tue Dec 17 17:11:55 2013 : Debug: 	max_request_time = 30
Tue Dec 17 17:11:55 2013 : Debug: 	cleanup_delay = 5
Tue Dec 17 17:11:55 2013 : Debug: 	max_requests = 1024
Tue Dec 17 17:11:55 2013 : Debug: 	pidfile = "/var/run/radiusd/radiusd.pid"
Tue Dec 17 17:11:55 2013 : Debug: 	checkrad = "/usr/sbin/checkrad"
Tue Dec 17 17:11:55 2013 : Debug: 	debug_level = 0
Tue Dec 17 17:11:55 2013 : Debug: 	proxy_requests = yes
Tue Dec 17 17:11:55 2013 : Debug:  log {
Tue Dec 17 17:11:55 2013 : Debug: 	stripped_names = no
Tue Dec 17 17:11:55 2013 : Debug: 	auth = no
Tue Dec 17 17:11:55 2013 : Debug: 	auth_badpass = no
Tue Dec 17 17:11:55 2013 : Debug: 	auth_goodpass = no
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  security {
Tue Dec 17 17:11:55 2013 : Debug: 	max_attributes = 200
Tue Dec 17 17:11:55 2013 : Debug: 	reject_delay = 1
Tue Dec 17 17:11:55 2013 : Debug: 	status_server = yes
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Debug: radiusd: #### Loading Realms and Home Servers ####
Tue Dec 17 17:11:55 2013 : Debug:  proxy server {
Tue Dec 17 17:11:55 2013 : Debug: 	retry_delay = 5
Tue Dec 17 17:11:55 2013 : Debug: 	retry_count = 3
Tue Dec 17 17:11:55 2013 : Debug: 	default_fallback = no
Tue Dec 17 17:11:55 2013 : Debug: 	dead_time = 120
Tue Dec 17 17:11:55 2013 : Debug: 	wake_all_if_all_dead = no
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  home_server localhost {
Tue Dec 17 17:11:55 2013 : Debug: 	ipaddr = 127.0.0.1
Tue Dec 17 17:11:55 2013 : Debug: 	port = 1812
Tue Dec 17 17:11:55 2013 : Debug: 	type = "auth"
Tue Dec 17 17:11:55 2013 : Debug: 	secret = "testing123"
Tue Dec 17 17:11:55 2013 : Debug: 	response_window = 20
Tue Dec 17 17:11:55 2013 : Debug: 	max_outstanding = 65536
Tue Dec 17 17:11:55 2013 : Debug: 	require_message_authenticator = yes
Tue Dec 17 17:11:55 2013 : Debug: 	zombie_period = 40
Tue Dec 17 17:11:55 2013 : Debug: 	status_check = "status-server"
Tue Dec 17 17:11:55 2013 : Debug: 	ping_interval = 30
Tue Dec 17 17:11:55 2013 : Debug: 	check_interval = 30
Tue Dec 17 17:11:55 2013 : Debug: 	num_answers_to_alive = 3
Tue Dec 17 17:11:55 2013 : Debug: 	num_pings_to_alive = 3
Tue Dec 17 17:11:55 2013 : Debug: 	revive_interval = 120
Tue Dec 17 17:11:55 2013 : Debug: 	status_check_timeout = 4
Tue Dec 17 17:11:55 2013 : Debug:   coa {
Tue Dec 17 17:11:55 2013 : Debug: 	irt = 2
Tue Dec 17 17:11:55 2013 : Debug: 	mrt = 16
Tue Dec 17 17:11:55 2013 : Debug: 	mrc = 5
Tue Dec 17 17:11:55 2013 : Debug: 	mrd = 30
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  home_server_pool my_auth_failover {
Tue Dec 17 17:11:55 2013 : Debug: 	type = fail-over
Tue Dec 17 17:11:55 2013 : Debug: 	home_server = localhost
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  realm example.com {
Tue Dec 17 17:11:55 2013 : Debug: 	auth_pool = my_auth_failover
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  realm LOCAL {
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug: radiusd: #### Loading Clients ####
Tue Dec 17 17:11:55 2013 : Debug:  client localhost {
Tue Dec 17 17:11:55 2013 : Debug: 	ipaddr = 127.0.0.1
Tue Dec 17 17:11:55 2013 : Debug: 	require_message_authenticator = no
Tue Dec 17 17:11:55 2013 : Debug: 	secret = "testing123"
Tue Dec 17 17:11:55 2013 : Debug: 	nastype = "other"
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug:  client 10.98.98.254 {
Tue Dec 17 17:11:55 2013 : Debug: 	require_message_authenticator = no
Tue Dec 17 17:11:55 2013 : Debug: 	secret = "d4t4c0mm"
Tue Dec 17 17:11:55 2013 : Debug: 	shortname = "ZDRuckus"
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug: radiusd: #### Instantiating modules ####
Tue Dec 17 17:11:55 2013 : Debug:  instantiate {
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_exec, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_exec
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "exec" from file /etc/raddb/modules/exec
Tue Dec 17 17:11:55 2013 : Debug:   exec {
Tue Dec 17 17:11:55 2013 : Debug: 	wait = no
Tue Dec 17 17:11:55 2013 : Debug: 	input_pairs = "request"
Tue Dec 17 17:11:55 2013 : Debug: 	shell_escape = yes
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_expr, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_expr
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "expr" from file /etc/raddb/modules/expr
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_expiration, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_expiration
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "expiration" from file /etc/raddb/modules/expiration
Tue Dec 17 17:11:55 2013 : Debug:   expiration {
Tue Dec 17 17:11:55 2013 : Debug: 	reply-message = "Password Has Expired  "
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_logintime, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_logintime
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime
Tue Dec 17 17:11:55 2013 : Debug:   logintime {
Tue Dec 17 17:11:55 2013 : Debug: 	reply-message = "You are calling outside your allowed timespan  "
Tue Dec 17 17:11:55 2013 : Debug: 	minimum-timeout = 60
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug: radiusd: #### Loading Virtual Servers ####
Tue Dec 17 17:11:55 2013 : Debug: server { # from file /etc/raddb/radiusd.conf
Tue Dec 17 17:11:55 2013 : Debug:  modules {
Tue Dec 17 17:11:55 2013 : Debug:   Module: Creating Auth-Type = ntlm_auth
Tue Dec 17 17:11:55 2013 : Debug:   Module: Creating Auth-Type = digest
Tue Dec 17 17:11:55 2013 : Debug:   Module: Creating Post-Auth-Type = REJECT
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking authenticate {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_pap, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_pap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "pap" from file /etc/raddb/modules/pap
Tue Dec 17 17:11:55 2013 : Debug:   pap {
Tue Dec 17 17:11:55 2013 : Debug: 	encryption_scheme = "auto"
Tue Dec 17 17:11:55 2013 : Debug: 	auto_header = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_chap, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_chap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "chap" from file /etc/raddb/modules/chap
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_mschap, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_mschap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap.backup
Tue Dec 17 17:11:55 2013 : Debug:   mschap {
Tue Dec 17 17:11:55 2013 : Debug: 	use_mppe = yes
Tue Dec 17 17:11:55 2013 : Debug: 	require_encryption = no
Tue Dec 17 17:11:55 2013 : Debug: 	require_strong = no
Tue Dec 17 17:11:55 2013 : Debug: 	with_ntdomain_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	allow_retry = yes
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "ntlm_auth" from file /etc/raddb/modules/ntlm_auth
Tue Dec 17 17:11:55 2013 : Debug:   exec ntlm_auth {
Tue Dec 17 17:11:55 2013 : Debug: 	wait = yes
Tue Dec 17 17:11:55 2013 : Debug: 	program = "/usr/bin/ntlm_auth --request-nt-key --domain=DATACOMM --username=%{mschap:User-Name} --password=%{User-Password}"
Tue Dec 17 17:11:55 2013 : Debug: 	input_pairs = "request"
Tue Dec 17 17:11:55 2013 : Debug: 	shell_escape = yes
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_digest, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_digest
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "digest" from file /etc/raddb/modules/digest
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_unix, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_unix
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "unix" from file /etc/raddb/modules/unix
Tue Dec 17 17:11:55 2013 : Debug:   unix {
Tue Dec 17 17:11:55 2013 : Debug: 	radwtmp = "/var/log/radius/radwtmp"
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_eap, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_eap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "eap" from file /etc/raddb/eap.conf
Tue Dec 17 17:11:55 2013 : Debug:   eap {
Tue Dec 17 17:11:55 2013 : Debug: 	default_eap_type = "ttls"
Tue Dec 17 17:11:55 2013 : Debug: 	timer_expire = 60
Tue Dec 17 17:11:55 2013 : Debug: 	ignore_unknown_eap_types = no
Tue Dec 17 17:11:55 2013 : Debug: 	cisco_accounting_username_bug = no
Tue Dec 17 17:11:55 2013 : Debug: 	max_sessions = 4096
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_md5
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-md5
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_leap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-leap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-gtc
Tue Dec 17 17:11:55 2013 : Debug:    gtc {
Tue Dec 17 17:11:55 2013 : Debug: 	challenge = "Password: "
Tue Dec 17 17:11:55 2013 : Debug: 	auth_type = "PAP"
Tue Dec 17 17:11:55 2013 : Debug:    }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_tls
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-tls
Tue Dec 17 17:11:55 2013 : Debug:    tls {
Tue Dec 17 17:11:55 2013 : Debug: 	rsa_key_exchange = no
Tue Dec 17 17:11:55 2013 : Debug: 	dh_key_exchange = yes
Tue Dec 17 17:11:55 2013 : Debug: 	rsa_key_length = 512
Tue Dec 17 17:11:55 2013 : Debug: 	dh_key_length = 512
Tue Dec 17 17:11:55 2013 : Debug: 	verify_depth = 0
Tue Dec 17 17:11:55 2013 : Debug: 	CA_path = "/etc/raddb/certs"
Tue Dec 17 17:11:55 2013 : Debug: 	pem_file_type = yes
Tue Dec 17 17:11:55 2013 : Debug: 	private_key_file = "/etc/raddb/certs/server.pem"
Tue Dec 17 17:11:55 2013 : Debug: 	certificate_file = "/etc/raddb/certs/server.pem"
Tue Dec 17 17:11:55 2013 : Debug: 	CA_file = "/etc/raddb/certs/ca.pem"
Tue Dec 17 17:11:55 2013 : Debug: 	private_key_password = "whatever"
Tue Dec 17 17:11:55 2013 : Debug: 	dh_file = "/etc/raddb/certs/dh"
Tue Dec 17 17:11:55 2013 : Debug: 	random_file = "/dev/urandom"
Tue Dec 17 17:11:55 2013 : Debug: 	fragment_size = 1024
Tue Dec 17 17:11:55 2013 : Debug: 	include_length = yes
Tue Dec 17 17:11:55 2013 : Debug: 	check_crl = no
Tue Dec 17 17:11:55 2013 : Debug: 	cipher_list = "DEFAULT"
Tue Dec 17 17:11:55 2013 : Debug:     cache {
Tue Dec 17 17:11:55 2013 : Debug: 	enable = no
Tue Dec 17 17:11:55 2013 : Debug: 	lifetime = 24
Tue Dec 17 17:11:55 2013 : Debug: 	max_entries = 255
Tue Dec 17 17:11:55 2013 : Debug:     }
Tue Dec 17 17:11:55 2013 : Debug:     verify {
Tue Dec 17 17:11:55 2013 : Debug:     }
Tue Dec 17 17:11:55 2013 : Debug:     ocsp {
Tue Dec 17 17:11:55 2013 : Debug: 	enable = no
Tue Dec 17 17:11:55 2013 : Debug: 	override_cert_url = yes
Tue Dec 17 17:11:55 2013 : Debug: 	url = "http://127.0.0.1/ocsp/"
Tue Dec 17 17:11:55 2013 : Debug:     }
Tue Dec 17 17:11:55 2013 : Debug:    }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-ttls
Tue Dec 17 17:11:55 2013 : Debug:    ttls {
Tue Dec 17 17:11:55 2013 : Debug: 	default_eap_type = "mschapv2"
Tue Dec 17 17:11:55 2013 : Debug: 	copy_request_to_tunnel = no
Tue Dec 17 17:11:55 2013 : Debug: 	use_tunneled_reply = no
Tue Dec 17 17:11:55 2013 : Debug: 	include_length = yes
Tue Dec 17 17:11:55 2013 : Debug:    }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_peap
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-peap
Tue Dec 17 17:11:55 2013 : Debug:    peap {
Tue Dec 17 17:11:55 2013 : Debug: 	default_eap_type = "mschapv2"
Tue Dec 17 17:11:55 2013 : Debug: 	copy_request_to_tunnel = no
Tue Dec 17 17:11:55 2013 : Debug: 	use_tunneled_reply = no
Tue Dec 17 17:11:55 2013 : Debug: 	proxy_tunneled_request_as_eap = yes
Tue Dec 17 17:11:55 2013 : Debug: 	soh = no
Tue Dec 17 17:11:55 2013 : Debug:    }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to sub-module rlm_eap_mschapv2
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating eap-mschapv2
Tue Dec 17 17:11:55 2013 : Debug:    mschapv2 {
Tue Dec 17 17:11:55 2013 : Debug: 	with_ntdomain_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	send_error = no
Tue Dec 17 17:11:55 2013 : Debug:    }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking authorize {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_preprocess, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_preprocess
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess
Tue Dec 17 17:11:55 2013 : Debug:   preprocess {
Tue Dec 17 17:11:55 2013 : Debug: 	huntgroups = "/etc/raddb/huntgroups"
Tue Dec 17 17:11:55 2013 : Debug: 	hints = "/etc/raddb/hints"
Tue Dec 17 17:11:55 2013 : Debug: 	with_ascend_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	ascend_channels_per_line = 23
Tue Dec 17 17:11:55 2013 : Debug: 	with_ntdomain_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	with_specialix_jetstream_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	with_cisco_vsa_hack = no
Tue Dec 17 17:11:55 2013 : Debug: 	with_alvarion_vsa_hack = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_detail, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_detail
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "auth_log" from file /etc/raddb/modules/detail.log
Tue Dec 17 17:11:55 2013 : Debug:   detail auth_log {
Tue Dec 17 17:11:55 2013 : Debug: 	detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
Tue Dec 17 17:11:55 2013 : Debug: 	header = "%t"
Tue Dec 17 17:11:55 2013 : Debug: 	detailperm = 384
Tue Dec 17 17:11:55 2013 : Debug: 	dirperm = 493
Tue Dec 17 17:11:55 2013 : Debug: 	locking = no
Tue Dec 17 17:11:55 2013 : Debug: 	log_packet_header = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_realm, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_realm
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "suffix" from file /etc/raddb/modules/realm
Tue Dec 17 17:11:55 2013 : Debug:   realm suffix {
Tue Dec 17 17:11:55 2013 : Debug: 	format = "suffix"
Tue Dec 17 17:11:55 2013 : Debug: 	delimiter = "@"
Tue Dec 17 17:11:55 2013 : Debug: 	ignore_default = no
Tue Dec 17 17:11:55 2013 : Debug: 	ignore_null = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "ntdomain" from file /etc/raddb/modules/realm
Tue Dec 17 17:11:55 2013 : Debug:   realm ntdomain {
Tue Dec 17 17:11:55 2013 : Debug: 	format = "prefix"
Tue Dec 17 17:11:55 2013 : Debug: 	delimiter = "\"
Tue Dec 17 17:11:55 2013 : Debug: 	ignore_default = no
Tue Dec 17 17:11:55 2013 : Debug: 	ignore_null = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_files, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_files
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "files" from file /etc/raddb/modules/files
Tue Dec 17 17:11:55 2013 : Debug:   files {
Tue Dec 17 17:11:55 2013 : Debug: 	usersfile = "/etc/raddb/users"
Tue Dec 17 17:11:55 2013 : Debug: 	acctusersfile = "/etc/raddb/acct_users"
Tue Dec 17 17:11:55 2013 : Debug: 	preproxy_usersfile = "/etc/raddb/preproxy_users"
Tue Dec 17 17:11:55 2013 : Debug: 	compat = "no"
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking preacct {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_acct_unique, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_acct_unique
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique
Tue Dec 17 17:11:55 2013 : Debug:   acct_unique {
Tue Dec 17 17:11:55 2013 : Debug: 	key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking accounting {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "detail" from file /etc/raddb/modules/detail
Tue Dec 17 17:11:55 2013 : Debug:   detail {
Tue Dec 17 17:11:55 2013 : Debug: 	detailfile = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
Tue Dec 17 17:11:55 2013 : Debug: 	header = "%t"
Tue Dec 17 17:11:55 2013 : Debug: 	detailperm = 384
Tue Dec 17 17:11:55 2013 : Debug: 	dirperm = 493
Tue Dec 17 17:11:55 2013 : Debug: 	locking = no
Tue Dec 17 17:11:55 2013 : Debug: 	log_packet_header = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_radutmp, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_radutmp
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp
Tue Dec 17 17:11:55 2013 : Debug:   radutmp {
Tue Dec 17 17:11:55 2013 : Debug: 	filename = "/var/log/radius/radutmp"
Tue Dec 17 17:11:55 2013 : Debug: 	username = "%{User-Name}"
Tue Dec 17 17:11:55 2013 : Debug: 	case_sensitive = yes
Tue Dec 17 17:11:55 2013 : Debug: 	check_with_nas = yes
Tue Dec 17 17:11:55 2013 : Debug: 	perm = 384
Tue Dec 17 17:11:55 2013 : Debug: 	callerid = yes
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:     (Loaded rlm_attr_filter, checking if it's valid)
Tue Dec 17 17:11:55 2013 : Debug:  Module: Linked to module rlm_attr_filter
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter
Tue Dec 17 17:11:55 2013 : Debug:   attr_filter attr_filter.accounting_response {
Tue Dec 17 17:11:55 2013 : Debug: 	attrsfile = "/etc/raddb/attrs.accounting_response"
Tue Dec 17 17:11:55 2013 : Debug: 	key = "%{User-Name}"
Tue Dec 17 17:11:55 2013 : Debug: 	relaxed = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking session {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking post-proxy {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking post-auth {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter
Tue Dec 17 17:11:55 2013 : Debug:   attr_filter attr_filter.access_reject {
Tue Dec 17 17:11:55 2013 : Debug: 	attrsfile = "/etc/raddb/attrs.access_reject"
Tue Dec 17 17:11:55 2013 : Debug: 	key = "%{User-Name}"
Tue Dec 17 17:11:55 2013 : Debug: 	relaxed = no
Tue Dec 17 17:11:55 2013 : Debug:   }
Tue Dec 17 17:11:55 2013 : Debug:  } # modules
Tue Dec 17 17:11:55 2013 : Debug: } # server
Tue Dec 17 17:11:55 2013 : Debug: server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
Tue Dec 17 17:11:55 2013 : Debug:  modules {
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking authenticate {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking authorize {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking session {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking post-proxy {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  Module: Checking post-auth {...} for more modules to load
Tue Dec 17 17:11:55 2013 : Debug:  } # modules
Tue Dec 17 17:11:55 2013 : Debug: } # server
Tue Dec 17 17:11:55 2013 : Debug: radiusd: #### Opening IP addresses and Ports ####
Tue Dec 17 17:11:55 2013 : Debug: listen {
Tue Dec 17 17:11:55 2013 : Debug: 	type = "auth"
Tue Dec 17 17:11:55 2013 : Debug: 	ipaddr = *
Tue Dec 17 17:11:55 2013 : Debug: 	port = 0
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Debug: listen {
Tue Dec 17 17:11:55 2013 : Debug: 	type = "acct"
Tue Dec 17 17:11:55 2013 : Debug: 	ipaddr = *
Tue Dec 17 17:11:55 2013 : Debug: 	port = 0
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Debug: listen {
Tue Dec 17 17:11:55 2013 : Debug: 	type = "control"
Tue Dec 17 17:11:55 2013 : Debug:  listen {
Tue Dec 17 17:11:55 2013 : Debug: 	socket = "/var/run/radiusd/radiusd.sock"
Tue Dec 17 17:11:55 2013 : Debug:  }
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Debug: listen {
Tue Dec 17 17:11:55 2013 : Debug: 	type = "auth"
Tue Dec 17 17:11:55 2013 : Debug: 	ipaddr = 127.0.0.1
Tue Dec 17 17:11:55 2013 : Debug: 	port = 18120
Tue Dec 17 17:11:55 2013 : Debug: }
Tue Dec 17 17:11:55 2013 : Info:  ... adding new socket proxy address * port 56329
Tue Dec 17 17:11:55 2013 : Debug: Listening on authentication address * port 1812
Tue Dec 17 17:11:55 2013 : Debug: Listening on accounting address * port 1813
Tue Dec 17 17:11:55 2013 : Debug: Listening on command file /var/run/radiusd/radiusd.sock
Tue Dec 17 17:11:55 2013 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel
Tue Dec 17 17:11:55 2013 : Debug: Listening on proxy address * port 1814
Tue Dec 17 17:11:55 2013 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=70, length=180
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x0200001301616e64692e6d61707065736f6e61
	Message-Authenticator = 0xe85893901a98e28b4f7044825b6ee7b2
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 0 length 19
Tue Dec 17 17:12:15 2013 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns updated
Tue Dec 17 17:12:15 2013 : Info: [files] users: Matched entry DEFAULT at line 1
Tue Dec 17 17:12:15 2013 : Info: ++[files] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[expiration] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[logintime] returns noop
Tue Dec 17 17:12:15 2013 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Tue Dec 17 17:12:15 2013 : Info: ++[pap] returns noop
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP Identity
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type tls
Tue Dec 17 17:12:15 2013 : Info: [tls] Initiate
Tue Dec 17 17:12:15 2013 : Info: [tls] Start returned 1
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 70 to 10.98.98.254 port 1624
	EAP-Message = 0x010100061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3851dae53850cfb7e50c0bd536802fbd
Tue Dec 17 17:12:15 2013 : Info: Finished request 0.
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=71, length=331
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x0201009815800000008e160301008901000085030152b022f395e14699b62bd124623d72242c7e7c88b8bba7bcfb711c93a218941c00004a00ffc024c023c00ac009c007c008c028c027c014c013c011c012c026c025c02ac029c005c004c002c003c00fc00ec00cc00d003d003c002f000500040035000a0067006b00330039001601000012000a00080006001700180019000b00020100
	State = 0x3851dae53850cfb7e50c0bd536802fbd
	Message-Authenticator = 0xa8c301c7334ed422088708b8b1c5ef8f
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 1 length 152
Tue Dec 17 17:12:15 2013 : Info: [eap] Continuing tunnel setup.
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns ok
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] Request found, released from the list
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type ttls
Tue Dec 17 17:12:15 2013 : Info: [ttls] Authenticate
Tue Dec 17 17:12:15 2013 : Info: [ttls] processing EAP-TLS
Tue Dec 17 17:12:15 2013 : Debug:   TLS Length 142
Tue Dec 17 17:12:15 2013 : Info: [ttls] Length Included
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_verify returned 11 
Tue Dec 17 17:12:15 2013 : Info: [ttls]     (other): before/accept initialization
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: before/accept initialization
Tue Dec 17 17:12:15 2013 : Info: [ttls] <<< TLS 1.0 Handshake [length 0089], ClientHello  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 read client hello A
Tue Dec 17 17:12:15 2013 : Info: [ttls] >>> TLS 1.0 Handshake [length 0031], ServerHello  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 write server hello A
Tue Dec 17 17:12:15 2013 : Info: [ttls] >>> TLS 1.0 Handshake [length 085e], Certificate  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 write certificate A
Tue Dec 17 17:12:15 2013 : Info: [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 write server done A
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 flush data
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
Tue Dec 17 17:12:15 2013 : Debug: In SSL Handshake Phase 
Tue Dec 17 17:12:15 2013 : Debug: In SSL Accept mode  
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_process returned 13 
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 71 to 10.98.98.254 port 1624
	EAP-Message = 0x0102040015c0000008a216030100310200002d030152b0237f44db6c60bc14b71742cc17a908de811b0790a3b848d484550d1d060e00002f000005ff01000100160301085e0b00085a0008570003a6308203a23082028aa003020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465204175
	EAP-Message = 0x74686f72697479301e170d3133313231333037313234335a170d3134303231313037313234335a307c310b3009060355040613024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c6520496e632e312330210603550403131a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100dba283b5fa31bf3aa3cfd8435f80f22e520a337ddcfa2239f97a8b578198b4441fea271c424f50deff81b51c1ff89689d5e954c617c3c3
	EAP-Message = 0x38bfc7381fba6fee33189fdde06048eead953c04ad98c3b44aa737fdecfaf07ccf378d027cee6f1d320280ee76a1573ad2a9b6d4bfa0c1c20c92ed55185cffa30f7566e9d10c6523665263bd2f52a22086149fc3166ab8f8d34fe295edbd8ef340cb2a99ed3a02dcdf9b9deaa6acdd668c5a0ce7e25ec504f1903762680ec811902f525755d03fd6fcf86ee7d62356662002a01a2030a9c932c448147e8d0b4489d5e25c50f5e2c5f88c20ed81a6d06ea36e7867a1e9c32698a8d3591c888295edf2dc5ce7de9939510203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000382010100495f
	EAP-Message = 0xaf011b843fa4b182cf8f436879b91b848fff88c6e0c1feb1c0b5b5db0edb8a887cdcd3e58b1596d345f33dc562523662d7a1f31e648d0014e1a280fb845360fbe2ee9c4b54c075d89b3cf4fa711ecba1c2aebec1171b838e4bbccd70bee91b7a356dab953ee739ccae19c31e2abb84c514ce24d4482a380c281db4666cb6a0b92948ccb1fd412145f42339d008be4b7d45adf0618d6d17adf460e68cf3a6cac4f762c24bda411dd86396bb10dc070690ee741f7774338d5a00e1da163d032e502422dfcdf051d3cb56d87ca3765a0414e7b9bfb1d35b14ca90d1ec41e30061d0137ab3260145ba8db10815eda1fa405bda99e5190c86347d122ffaa1f6
	EAP-Message = 0x5f0004ab308204a73082038f
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3851dae53953cfb7e50c0bd536802fbd
Tue Dec 17 17:12:15 2013 : Info: Finished request 1.
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=72, length=185
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x020200061500
	State = 0x3851dae53953cfb7e50c0bd536802fbd
	Message-Authenticator = 0x762bb66f7fdc923d5f6e86883b1fbe81
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 2 length 6
Tue Dec 17 17:12:15 2013 : Info: [eap] Continuing tunnel setup.
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns ok
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] Request found, released from the list
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type ttls
Tue Dec 17 17:12:15 2013 : Info: [ttls] Authenticate
Tue Dec 17 17:12:15 2013 : Info: [ttls] processing EAP-TLS
Tue Dec 17 17:12:15 2013 : Info: [ttls] Received TLS ACK
Tue Dec 17 17:12:15 2013 : Info: [ttls] ACK handshake fragment handler
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_verify returned 1 
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_process returned 13 
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 72 to 10.98.98.254 port 1624
	EAP-Message = 0x0103040015c0000008a2a0030201020209009aa6bdae4911e4c9300d06092a864886f70d0101050500308193310b3009060355040613024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d3133313231333037313234335a170d3134303231313037313234335a308193310b3009060355040613024652310f300d06035504081306526164
	EAP-Message = 0x6975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a0282010100bbf83ae61660ad452c40335e0d37c323437eaf8eec697ae459a384c0357a7121c5bf56d235872cc48544a6d210cff1d0b1da63a86ee4f2d05559c37f3aa18228f5c702aae9de5c3cdd01bd2815cd8873fd8c4caf697b19355a7987fc36e8eaf76cb16720
	EAP-Message = 0x89416dede2bf08ce0886e71ccdc0018f88adc638ba27a350c5b1c5e4502d01593eb54fc2429ada18f1e1976b66b1298f6ff752d4e90ebcb7fd2af00daecb8df51c62bb457e4c9bb022daa230d67f12cda42c43a42cdf79fe45b7122ca60acae6c7b0790a8a8bcd32a11f0fcdfc07ad73a312c50d2bb2a4c5ac2fe241d070d6af3eedc00dee4b606eb38b370c1765a693860bdbb0ca6057b6f4160e430203010001a381fb3081f8301d0603551d0e04160414b767fec6840084cd89b1642bc20b56986ae612c83081c80603551d230481c03081bd8014b767fec6840084cd89b1642bc20b56986ae612c8a18199a48196308193310b3009060355040613
	EAP-Message = 0x024652310f300d060355040813065261646975733112301006035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520417574686f726974798209009aa6bdae4911e4c9300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100815a605ac77c93970185d3f6975a1627d5af783d095cd6e8a0ab64196391ecf4cec9d509d22662f162d306974425597f5ea2e8e68ffa24b6097c7c163f0b344ed199efe751f59a
	EAP-Message = 0xa7f3b100283b3b13b63e59bc
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3851dae53a52cfb7e50c0bd536802fbd
Tue Dec 17 17:12:15 2013 : Info: Finished request 2.
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=73, length=185
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x020300061500
	State = 0x3851dae53a52cfb7e50c0bd536802fbd
	Message-Authenticator = 0xb6410b287bee939e553fd9b5ab69684a
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 3 length 6
Tue Dec 17 17:12:15 2013 : Info: [eap] Continuing tunnel setup.
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns ok
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] Request found, released from the list
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type ttls
Tue Dec 17 17:12:15 2013 : Info: [ttls] Authenticate
Tue Dec 17 17:12:15 2013 : Info: [ttls] processing EAP-TLS
Tue Dec 17 17:12:15 2013 : Info: [ttls] Received TLS ACK
Tue Dec 17 17:12:15 2013 : Info: [ttls] ACK handshake fragment handler
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_verify returned 1 
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_process returned 13 
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 73 to 10.98.98.254 port 1624
	EAP-Message = 0x010400c01580000008a2034823274b6525c7196918d495e904ce808a3f972461536b6975f46632d568c1a2849ed6007bd03177480a3d8d00b2d3267ec668cb42cd7095f20b26a930aba66509e0ce2451d0bdd4c47823bf73a9e49c04e153826d1a9ec5f7d97675d85eada99a6fe486c4413d897848d434246ef1cb097fd929eab195b4a173f6832a95b2aba9a3840c91ec9d4f4c4e0e7b83e8bac0e64f260aa69356312f03ad6da8f95c9486cdf1bf5e12d457e60f91a116030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3851dae53b55cfb7e50c0bd536802fbd
Tue Dec 17 17:12:15 2013 : Info: Finished request 3.
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=74, length=517
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x0204015015800000014616030101061000010201004a3889fa56ff1fb493da06cff8bb5700057f6cab1845c032fd89e6c63b01ecb716e3856019de653d5a4bcef91fb4c7abb29bc6e1eb2f3365d30a65180af6c7be1683abe60ebfcb328f4d8a2611e34ff6b4880a0fd09319bcb01132ca964268ac5f2bd5ea42124900bf6b376072a3c2c02286e71c653165695dfb309b1850d908503898aeef2d0105cecfa48a2f29b115d1aedcd5eece5d8a79a3468422852b23f12f372f0df4ef051685603d95f49e65823cde31c3f003be7f8f0056c62d99e44dc7cd95f3fa03c6a38c585074a6d500289b764c314b6886dcadd5ee8ae9ee9a0e342a5a64a5232f
	EAP-Message = 0x9da739b8eaffe857fb9027c7ecb6b44dbb60ac7cdadd0b3b1403010001011603010030fef2d492fa835a10e217fa68c11e133e4c65f1b05b6bd40c1a3d210cd44032f854f1ab6fdd183475bb6c88c4a36f7eb2
	State = 0x3851dae53b55cfb7e50c0bd536802fbd
	Message-Authenticator = 0x7db757211c84fee33abcf4de984e1c3f
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 4 length 253
Tue Dec 17 17:12:15 2013 : Info: [eap] Continuing tunnel setup.
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns ok
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] Request found, released from the list
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type ttls
Tue Dec 17 17:12:15 2013 : Info: [ttls] Authenticate
Tue Dec 17 17:12:15 2013 : Info: [ttls] processing EAP-TLS
Tue Dec 17 17:12:15 2013 : Debug:   TLS Length 326
Tue Dec 17 17:12:15 2013 : Info: [ttls] Length Included
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_verify returned 11 
Tue Dec 17 17:12:15 2013 : Info: [ttls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 read client key exchange A
Tue Dec 17 17:12:15 2013 : Info: [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
Tue Dec 17 17:12:15 2013 : Info: [ttls] <<< TLS 1.0 Handshake [length 0010], Finished  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 read finished A
Tue Dec 17 17:12:15 2013 : Info: [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 write change cipher spec A
Tue Dec 17 17:12:15 2013 : Info: [ttls] >>> TLS 1.0 Handshake [length 0010], Finished  
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 write finished A
Tue Dec 17 17:12:15 2013 : Info: [ttls]     TLS_accept: SSLv3 flush data
Tue Dec 17 17:12:15 2013 : Info: [ttls]     (other): SSL negotiation finished successfully
Tue Dec 17 17:12:15 2013 : Debug: SSL Connection Established 
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_process returned 13 
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 74 to 10.98.98.254 port 1624
	EAP-Message = 0x0105004515800000003b14030100010116030100306293a99868fc4d2e9fee63bc9abe5f4d75f8aafab75d37c676f58af4b0e0fc945b7a19b52b6e1c0b3ad594d6e916a43a
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x3851dae53c54cfb7e50c0bd536802fbd
Tue Dec 17 17:12:15 2013 : Info: Finished request 4.
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.98.98.254 port 1624, id=75, length=338
	User-Name = "andi.mappesona"
	NAS-IP-Address = 10.98.98.254
	NAS-Identifier = "74-91-1A-27-B3-DA"
	NAS-Port = 1
	Called-Station-Id = "74-91-1A-27-B3-DA"
	Calling-Station-Id = "C0-9F-42-CF-4F-DF"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "CONNECT 11Mbps 802.11b"
	EAP-Message = 0x0205009f1580000000951703010090e3b3b21fcf7d430468504faa7005052413cdf36963a03ce550150c873f58658ca2ccb55760d7fd2878ddf62f6968670e42f1a8a2c9b679c23aa2d5ccaed5076bcbe4c88a6572ab6ffa83083e76b328e9ab9740e62ed163ebda7d94dc6570b2d704cf316310a45b788fbff95f7db07bb2446ca8da278d6b4f4b1df5f1f4f74dce0279c7ef5ddf947660f2f36b3bba31af
	State = 0x3851dae53c54cfb7e50c0bd536802fbd
	Message-Authenticator = 0x55f2c71e463c8d871548ceab740d03c6
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP packet type response id 5 length 159
Tue Dec 17 17:12:15 2013 : Info: [eap] Continuing tunnel setup.
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns ok
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = EAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authenticate {...}
Tue Dec 17 17:12:15 2013 : Info: [eap] Request found, released from the list
Tue Dec 17 17:12:15 2013 : Info: [eap] EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] processing type ttls
Tue Dec 17 17:12:15 2013 : Info: [ttls] Authenticate
Tue Dec 17 17:12:15 2013 : Info: [ttls] processing EAP-TLS
Tue Dec 17 17:12:15 2013 : Debug:   TLS Length 149
Tue Dec 17 17:12:15 2013 : Info: [ttls] Length Included
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_verify returned 11 
Tue Dec 17 17:12:15 2013 : Info: [ttls] eaptls_process returned 7 
Tue Dec 17 17:12:15 2013 : Info: [ttls] Session established.  Proceeding to decode tunneled attributes.
Tue Dec 17 17:12:15 2013 : Info: [ttls] Got tunneled request
	User-Name = "andi.mappesona"
	MS-CHAP-Challenge = 0x4252b1eb093cab7b65d1209250b9e20c
	MS-CHAP2-Response = 0xf100c85fb075bab0665b5e62c868af673c0d0000000000000000a8d1edcc1fab2ba9fcf936a4fe0bcbd1b28df61ca0c96ead
	FreeRADIUS-Proxied-To = 127.0.0.1
Tue Dec 17 17:12:15 2013 : Info: [ttls] Sending tunneled request
	User-Name = "andi.mappesona"
	MS-CHAP-Challenge = 0x4252b1eb093cab7b65d1209250b9e20c
	MS-CHAP2-Response = 0xf100c85fb075bab0665b5e62c868af673c0d0000000000000000a8d1edcc1fab2ba9fcf936a4fe0bcbd1b28df61ca0c96ead
	FreeRADIUS-Proxied-To = 127.0.0.1
server  {
Tue Dec 17 17:12:15 2013 : Info: # Executing section authorize from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group authorize {...}
Tue Dec 17 17:12:15 2013 : Info: ++[preprocess] returns ok
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/10.98.98.254/auth-detail-20131217
Tue Dec 17 17:12:15 2013 : Info: [auth_log] 	expand: %t -> Tue Dec 17 17:12:15 2013
Tue Dec 17 17:12:15 2013 : Info: ++[auth_log] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[chap] returns noop
Tue Dec 17 17:12:15 2013 : Info: [mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[digest] returns noop
Tue Dec 17 17:12:15 2013 : Info: [suffix] No '@' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [suffix] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[suffix] returns noop
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No '\' in User-Name = "andi.mappesona", looking up realm NULL
Tue Dec 17 17:12:15 2013 : Info: [ntdomain] No such realm "NULL"
Tue Dec 17 17:12:15 2013 : Info: ++[ntdomain] returns noop
Tue Dec 17 17:12:15 2013 : Info: [eap] No EAP-Message, not doing EAP
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns noop
Tue Dec 17 17:12:15 2013 : Info: [files] users: Matched entry DEFAULT at line 1
Tue Dec 17 17:12:15 2013 : Info: ++[files] returns ok
Tue Dec 17 17:12:15 2013 : Info: ++[expiration] returns noop
Tue Dec 17 17:12:15 2013 : Info: ++[logintime] returns noop
Tue Dec 17 17:12:15 2013 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Tue Dec 17 17:12:15 2013 : Info: ++[pap] returns noop
Tue Dec 17 17:12:15 2013 : Info: Found Auth-Type = MSCHAP
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group MS-CHAP {...}
Tue Dec 17 17:12:15 2013 : Info: [mschap] No Cleartext-Password configured.  Cannot create LM-Password.
Tue Dec 17 17:12:15 2013 : Info: [mschap] No Cleartext-Password configured.  Cannot create NT-Password.
Tue Dec 17 17:12:15 2013 : Info: [mschap] Creating challenge hash with username: andi.mappesona
Tue Dec 17 17:12:15 2013 : Info: [mschap] Told to do MS-CHAPv2 for andi.mappesona with NT-Password
Tue Dec 17 17:12:15 2013 : Info: [mschap] FAILED: No NT/LM-Password.  Cannot perform authentication.
Tue Dec 17 17:12:15 2013 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect
Tue Dec 17 17:12:15 2013 : Info: ++[mschap] returns reject
Tue Dec 17 17:12:15 2013 : Info: Failed to authenticate the user.
} # server 
Tue Dec 17 17:12:15 2013 : Info: [ttls] Got tunneled reply code 3
	MS-CHAP-Error = "\361E=691 R=1"
Tue Dec 17 17:12:15 2013 : Info: [ttls] Got tunneled Access-Reject
Tue Dec 17 17:12:15 2013 : Info: [eap] Handler failed in EAP/ttls
Tue Dec 17 17:12:15 2013 : Info: [eap] Failed in EAP select
Tue Dec 17 17:12:15 2013 : Info: ++[eap] returns invalid
Tue Dec 17 17:12:15 2013 : Info: Failed to authenticate the user.
Tue Dec 17 17:12:15 2013 : Info: Using Post-Auth-Type Reject
Tue Dec 17 17:12:15 2013 : Info: # Executing group from file /etc/raddb/sites-enabled/default
Tue Dec 17 17:12:15 2013 : Info: +- entering group REJECT {...}
Tue Dec 17 17:12:15 2013 : Info: [attr_filter.access_reject] 	expand: %{User-Name} -> andi.mappesona
Tue Dec 17 17:12:15 2013 : Debug: attr_filter: Matched entry DEFAULT at line 11
Tue Dec 17 17:12:15 2013 : Info: ++[attr_filter.access_reject] returns updated
Tue Dec 17 17:12:15 2013 : Info: Delaying reject of request 5 for 1 seconds
Tue Dec 17 17:12:15 2013 : Debug: Going to the next request
Tue Dec 17 17:12:15 2013 : Debug: Waking up in 0.9 seconds.
Tue Dec 17 17:12:16 2013 : Info: Sending delayed reject for request 5
Sending Access-Reject of id 75 to 10.98.98.254 port 1624
	EAP-Message = 0x04050004
	Message-Authenticator = 0x00000000000000000000000000000000
Tue Dec 17 17:12:16 2013 : Debug: Waking up in 3.8 seconds.
Tue Dec 17 17:12:20 2013 : Info: Cleaning up request 0 ID 70 with timestamp +20
Tue Dec 17 17:12:20 2013 : Info: Cleaning up request 1 ID 71 with timestamp +20
Tue Dec 17 17:12:20 2013 : Info: Cleaning up request 2 ID 72 with timestamp +20
Tue Dec 17 17:12:20 2013 : Info: Cleaning up request 3 ID 73 with timestamp +20
Tue Dec 17 17:12:20 2013 : Info: Cleaning up request 4 ID 74 with timestamp +20
Tue Dec 17 17:12:20 2013 : Debug: Waking up in 1.0 seconds.
Tue Dec 17 17:12:21 2013 : Info: Cleaning up request 5 ID 75 with timestamp +20
Tue Dec 17 17:12:21 2013 : Info: Ready to process requests.