Fri Apr  9 05:12:31 2010 : Info: FreeRADIUS Version 2.1.6, for host i686-pc-linux-gnu, built on Sep 12 2009 at 16:50:08
Fri Apr  9 05:12:31 2010 : Info: Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. 
Fri Apr  9 05:12:31 2010 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
Fri Apr  9 05:12:31 2010 : Info: PARTICULAR PURPOSE. 
Fri Apr  9 05:12:31 2010 : Info: You may redistribute copies of FreeRADIUS under the terms of the 
Fri Apr  9 05:12:31 2010 : Info: GNU General Public License v2. 
Fri Apr  9 05:12:31 2010 : Info: Starting - reading configuration files ...
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/clients.conf
Fri Apr  9 05:12:31 2010 : Debug: including files in directory /usr/local/etc/raddb/modules/
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/otp
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/pap
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/unix
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/files
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/realm
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/perl
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/exec
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/always
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/echo
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/counter
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/policy
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/expr
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/digest
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/pam
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/detail
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/modules/chap
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/eap.conf
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/policy.conf
Fri Apr  9 05:12:31 2010 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Fri Apr  9 05:12:31 2010 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default
Fri Apr  9 05:12:31 2010 : Debug: including dictionary file /usr/local/etc/raddb/dictionary
Fri Apr  9 05:12:31 2010 : Debug: main {
Fri Apr  9 05:12:31 2010 : Debug: 	prefix = "/usr/local"
Fri Apr  9 05:12:31 2010 : Debug: 	localstatedir = "/usr/local/var"
Fri Apr  9 05:12:31 2010 : Debug: 	logdir = "/usr/local/var/log/radius"
Fri Apr  9 05:12:31 2010 : Debug: 	libdir = "/usr/local/lib"
Fri Apr  9 05:12:31 2010 : Debug: 	radacctdir = "/usr/local/var/log/radius/radacct"
Fri Apr  9 05:12:31 2010 : Debug: 	hostname_lookups = no
Fri Apr  9 05:12:31 2010 : Debug: 	max_request_time = 30
Fri Apr  9 05:12:31 2010 : Debug: 	cleanup_delay = 5
Fri Apr  9 05:12:31 2010 : Debug: 	max_requests = 1024
Fri Apr  9 05:12:31 2010 : Debug: 	allow_core_dumps = no
Fri Apr  9 05:12:31 2010 : Debug: 	pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Fri Apr  9 05:12:31 2010 : Debug: 	checkrad = "/usr/local/sbin/checkrad"
Fri Apr  9 05:12:31 2010 : Debug: 	debug_level = 0
Fri Apr  9 05:12:31 2010 : Debug: 	proxy_requests = yes
Fri Apr  9 05:12:31 2010 : Debug:  log {
Fri Apr  9 05:12:31 2010 : Debug: 	stripped_names = no
Fri Apr  9 05:12:31 2010 : Debug: 	auth = no
Fri Apr  9 05:12:31 2010 : Debug: 	auth_badpass = no
Fri Apr  9 05:12:31 2010 : Debug: 	auth_goodpass = no
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  security {
Fri Apr  9 05:12:31 2010 : Debug: 	max_attributes = 200
Fri Apr  9 05:12:31 2010 : Debug: 	reject_delay = 1
Fri Apr  9 05:12:31 2010 : Debug: 	status_server = yes
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug: }
Fri Apr  9 05:12:31 2010 : Debug: radiusd: #### Loading Realms and Home Servers ####
Fri Apr  9 05:12:31 2010 : Debug:  proxy server {
Fri Apr  9 05:12:31 2010 : Debug: 	retry_delay = 5
Fri Apr  9 05:12:31 2010 : Debug: 	retry_count = 3
Fri Apr  9 05:12:31 2010 : Debug: 	default_fallback = no
Fri Apr  9 05:12:31 2010 : Debug: 	dead_time = 120
Fri Apr  9 05:12:31 2010 : Debug: 	wake_all_if_all_dead = no
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  home_server localhost {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 127.0.0.1
Fri Apr  9 05:12:31 2010 : Debug: 	port = 1812
Fri Apr  9 05:12:31 2010 : Debug: 	type = "auth"
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "testing123"
Fri Apr  9 05:12:31 2010 : Debug: 	response_window = 20
Fri Apr  9 05:12:31 2010 : Debug: 	max_outstanding = 65536
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	zombie_period = 40
Fri Apr  9 05:12:31 2010 : Debug: 	status_check = "status-server"
Fri Apr  9 05:12:31 2010 : Debug: 	ping_interval = 30
Fri Apr  9 05:12:31 2010 : Debug: 	check_interval = 30
Fri Apr  9 05:12:31 2010 : Debug: 	num_answers_to_alive = 3
Fri Apr  9 05:12:31 2010 : Debug: 	num_pings_to_alive = 3
Fri Apr  9 05:12:31 2010 : Debug: 	revive_interval = 120
Fri Apr  9 05:12:31 2010 : Debug: 	status_check_timeout = 4
Fri Apr  9 05:12:31 2010 : Debug: 	irt = 2
Fri Apr  9 05:12:31 2010 : Debug: 	mrt = 16
Fri Apr  9 05:12:31 2010 : Debug: 	mrc = 5
Fri Apr  9 05:12:31 2010 : Debug: 	mrd = 30
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  home_server_pool my_auth_failover {
Fri Apr  9 05:12:31 2010 : Debug: 	type = fail-over
Fri Apr  9 05:12:31 2010 : Debug: 	home_server = localhost
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  realm example.com {
Fri Apr  9 05:12:31 2010 : Debug: 	auth_pool = my_auth_failover
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  realm LOCAL {
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug: radiusd: #### Loading Clients ####
Fri Apr  9 05:12:31 2010 : Debug:  client localhost {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 127.0.0.1
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "testing123"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  client 10.32.49.91 {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 10.32.49.91
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "password"
Fri Apr  9 05:12:31 2010 : Debug: 	shortname = "switch"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug: 	login = "testuser"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  client 10.32.49.92 {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 10.32.49.92
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "password"
Fri Apr  9 05:12:31 2010 : Debug: 	shortname = "switch"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug: 	login = "testuser"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  client 10.32.49.88 {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 10.32.49.88
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "password"
Fri Apr  9 05:12:31 2010 : Debug: 	shortname = "switch"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug: 	login = "testuser"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  client 10.32.57.100 {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 10.32.57.100
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "password"
Fri Apr  9 05:12:31 2010 : Debug: 	shortname = "switch"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug: 	login = "testuser"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug:  client 10.37.18.108 {
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = 10.37.18.108
Fri Apr  9 05:12:31 2010 : Debug: 	require_message_authenticator = no
Fri Apr  9 05:12:31 2010 : Debug: 	secret = "sharedsecret"
Fri Apr  9 05:12:31 2010 : Debug: 	shortname = "switch"
Fri Apr  9 05:12:31 2010 : Debug: 	nastype = "other"
Fri Apr  9 05:12:31 2010 : Debug: 	login = "testuser"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug: radiusd: #### Instantiating modules ####
Fri Apr  9 05:12:31 2010 : Debug:  instantiate {
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_exec, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_exec
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating exec
Fri Apr  9 05:12:31 2010 : Debug:   exec {
Fri Apr  9 05:12:31 2010 : Debug: 	wait = no
Fri Apr  9 05:12:31 2010 : Debug: 	input_pairs = "request"
Fri Apr  9 05:12:31 2010 : Debug: 	shell_escape = yes
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_expr, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_expr
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating expr
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_expiration, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_expiration
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating expiration
Fri Apr  9 05:12:31 2010 : Debug:   expiration {
Fri Apr  9 05:12:31 2010 : Debug: 	reply-message = "Password Has Expired  "
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_logintime, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_logintime
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating logintime
Fri Apr  9 05:12:31 2010 : Debug:   logintime {
Fri Apr  9 05:12:31 2010 : Debug: 	reply-message = "You are calling outside your allowed timespan  "
Fri Apr  9 05:12:31 2010 : Debug: 	minimum-timeout = 60
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug: radiusd: #### Loading Virtual Servers ####
Fri Apr  9 05:12:31 2010 : Debug: server inner-tunnel {
Fri Apr  9 05:12:31 2010 : Debug:  modules {
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_pap, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_pap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating pap
Fri Apr  9 05:12:31 2010 : Debug:   pap {
Fri Apr  9 05:12:31 2010 : Debug: 	encryption_scheme = "auto"
Fri Apr  9 05:12:31 2010 : Debug: 	auto_header = no
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_chap, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_chap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating chap
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_mschap, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_mschap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating mschap
Fri Apr  9 05:12:31 2010 : Debug:   mschap {
Fri Apr  9 05:12:31 2010 : Debug: 	use_mppe = yes
Fri Apr  9 05:12:31 2010 : Debug: 	require_encryption = no
Fri Apr  9 05:12:31 2010 : Debug: 	require_strong = no
Fri Apr  9 05:12:31 2010 : Debug: 	with_ntdomain_hack = no
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_unix, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_unix
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating unix
Fri Apr  9 05:12:31 2010 : Debug:   unix {
Fri Apr  9 05:12:31 2010 : Debug: 	radwtmp = "/usr/local/var/log/radius/radwtmp"
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_eap, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_eap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap
Fri Apr  9 05:12:31 2010 : Debug:   eap {
Fri Apr  9 05:12:31 2010 : Debug: 	default_eap_type = "peap"
Fri Apr  9 05:12:31 2010 : Debug: 	timer_expire = 60
Fri Apr  9 05:12:31 2010 : Debug: 	ignore_unknown_eap_types = no
Fri Apr  9 05:12:31 2010 : Debug: 	cisco_accounting_username_bug = no
Fri Apr  9 05:12:31 2010 : Debug: 	max_sessions = 2048
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_md5
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-md5
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_leap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-leap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_gtc
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-gtc
Fri Apr  9 05:12:31 2010 : Debug:    gtc {
Fri Apr  9 05:12:31 2010 : Debug: 	challenge = "Password: "
Fri Apr  9 05:12:31 2010 : Debug: 	auth_type = "PAP"
Fri Apr  9 05:12:31 2010 : Debug:    }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_tls
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-tls
Fri Apr  9 05:12:31 2010 : Debug:    tls {
Fri Apr  9 05:12:31 2010 : Debug: 	rsa_key_exchange = no
Fri Apr  9 05:12:31 2010 : Debug: 	dh_key_exchange = yes
Fri Apr  9 05:12:31 2010 : Debug: 	rsa_key_length = 512
Fri Apr  9 05:12:31 2010 : Debug: 	dh_key_length = 512
Fri Apr  9 05:12:31 2010 : Debug: 	verify_depth = 0
Fri Apr  9 05:12:31 2010 : Debug: 	pem_file_type = yes
Fri Apr  9 05:12:31 2010 : Debug: 	private_key_file = "/root/SW/Xsupplicant/keyname.pem"
Fri Apr  9 05:12:31 2010 : Debug: 	certificate_file = "/root/SW/Xsupplicant/certnew.pem"
Fri Apr  9 05:12:31 2010 : Debug: 	CA_file = "/root/SW/Xsupplicant/root_cert.pem"
Fri Apr  9 05:12:31 2010 : Debug: 	private_key_password = "password"
Fri Apr  9 05:12:31 2010 : Debug: 	dh_file = "/usr/local/etc/raddb/certs/dh"
Fri Apr  9 05:12:31 2010 : Debug: 	random_file = "/dev/urandom"
Fri Apr  9 05:12:31 2010 : Debug: 	fragment_size = 1024
Fri Apr  9 05:12:31 2010 : Debug: 	include_length = yes
Fri Apr  9 05:12:31 2010 : Debug: 	check_crl = no
Fri Apr  9 05:12:31 2010 : Debug: 	cipher_list = "DEFAULT"
Fri Apr  9 05:12:31 2010 : Debug: 	make_cert_command = "/usr/local/etc/raddb/certs/bootstrap"
Fri Apr  9 05:12:31 2010 : Debug:     cache {
Fri Apr  9 05:12:31 2010 : Debug: 	enable = no
Fri Apr  9 05:12:31 2010 : Debug: 	lifetime = 24
Fri Apr  9 05:12:31 2010 : Debug: 	max_entries = 255
Fri Apr  9 05:12:31 2010 : Debug:     }
Fri Apr  9 05:12:31 2010 : Debug:    }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_ttls
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-ttls
Fri Apr  9 05:12:31 2010 : Debug:    ttls {
Fri Apr  9 05:12:31 2010 : Debug: 	default_eap_type = "mschapv2"
Fri Apr  9 05:12:31 2010 : Debug: 	copy_request_to_tunnel = no
Fri Apr  9 05:12:31 2010 : Debug: 	use_tunneled_reply = no
Fri Apr  9 05:12:31 2010 : Debug: 	virtual_server = "inner-tunnel"
Fri Apr  9 05:12:31 2010 : Debug: 	include_length = yes
Fri Apr  9 05:12:31 2010 : Debug:    }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_peap
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-peap
Fri Apr  9 05:12:31 2010 : Debug:    peap {
Fri Apr  9 05:12:31 2010 : Debug: 	default_eap_type = "mschapv2"
Fri Apr  9 05:12:31 2010 : Debug: 	copy_request_to_tunnel = no
Fri Apr  9 05:12:31 2010 : Debug: 	use_tunneled_reply = no
Fri Apr  9 05:12:31 2010 : Debug: 	proxy_tunneled_request_as_eap = yes
Fri Apr  9 05:12:31 2010 : Debug: 	virtual_server = "inner-tunnel"
Fri Apr  9 05:12:31 2010 : Debug:    }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to sub-module rlm_eap_mschapv2
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating eap-mschapv2
Fri Apr  9 05:12:31 2010 : Debug:    mschapv2 {
Fri Apr  9 05:12:31 2010 : Debug: 	with_ntdomain_hack = no
Fri Apr  9 05:12:31 2010 : Debug:    }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_realm, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_realm
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating suffix
Fri Apr  9 05:12:31 2010 : Debug:   realm suffix {
Fri Apr  9 05:12:31 2010 : Debug: 	format = "suffix"
Fri Apr  9 05:12:31 2010 : Debug: 	delimiter = "@"
Fri Apr  9 05:12:31 2010 : Debug: 	ignore_default = no
Fri Apr  9 05:12:31 2010 : Debug: 	ignore_null = no
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_files, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_files
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating files
Fri Apr  9 05:12:31 2010 : Debug:   files {
Fri Apr  9 05:12:31 2010 : Debug: 	usersfile = "/usr/local/etc/raddb/users"
Fri Apr  9 05:12:31 2010 : Debug: 	acctusersfile = "/usr/local/etc/raddb/acct_users"
Fri Apr  9 05:12:31 2010 : Debug: 	preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
Fri Apr  9 05:12:31 2010 : Debug: 	compat = "no"
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking session {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_radutmp, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_radutmp
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating radutmp
Fri Apr  9 05:12:31 2010 : Debug:   radutmp {
Fri Apr  9 05:12:31 2010 : Debug: 	filename = "/usr/local/var/log/radius/radutmp"
Fri Apr  9 05:12:31 2010 : Debug: 	username = "%{User-Name}"
Fri Apr  9 05:12:31 2010 : Debug: 	case_sensitive = yes
Fri Apr  9 05:12:31 2010 : Debug: 	check_with_nas = yes
Fri Apr  9 05:12:31 2010 : Debug: 	perm = 384
Fri Apr  9 05:12:31 2010 : Debug: 	callerid = yes
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_attr_filter, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_attr_filter
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating attr_filter.access_reject
Fri Apr  9 05:12:31 2010 : Debug:   attr_filter attr_filter.access_reject {
Fri Apr  9 05:12:31 2010 : Debug: 	attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
Fri Apr  9 05:12:31 2010 : Debug: 	key = "%{User-Name}"
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  } # modules
Fri Apr  9 05:12:31 2010 : Debug: } # server
Fri Apr  9 05:12:31 2010 : Debug: server {
Fri Apr  9 05:12:31 2010 : Debug:  modules {
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking authenticate {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking authorize {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_preprocess, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_preprocess
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating preprocess
Fri Apr  9 05:12:31 2010 : Debug:   preprocess {
Fri Apr  9 05:12:31 2010 : Debug: 	huntgroups = "/usr/local/etc/raddb/huntgroups"
Fri Apr  9 05:12:31 2010 : Debug: 	hints = "/usr/local/etc/raddb/hints"
Fri Apr  9 05:12:31 2010 : Debug: 	with_ascend_hack = no
Fri Apr  9 05:12:31 2010 : Debug: 	ascend_channels_per_line = 23
Fri Apr  9 05:12:31 2010 : Debug: 	with_ntdomain_hack = no
Fri Apr  9 05:12:31 2010 : Debug: 	with_specialix_jetstream_hack = no
Fri Apr  9 05:12:31 2010 : Debug: 	with_cisco_vsa_hack = no
Fri Apr  9 05:12:31 2010 : Debug: 	with_alvarion_vsa_hack = no
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking preacct {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_acct_unique, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_acct_unique
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating acct_unique
Fri Apr  9 05:12:31 2010 : Debug:   acct_unique {
Fri Apr  9 05:12:31 2010 : Debug: 	key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking accounting {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:     (Loaded rlm_detail, checking if it's valid)
Fri Apr  9 05:12:31 2010 : Debug:  Module: Linked to module rlm_detail
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating detail
Fri Apr  9 05:12:31 2010 : Debug:   detail {
Fri Apr  9 05:12:31 2010 : Debug: 	detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Fri Apr  9 05:12:31 2010 : Debug: 	header = "%t"
Fri Apr  9 05:12:31 2010 : Debug: 	detailperm = 384
Fri Apr  9 05:12:31 2010 : Debug: 	dirperm = 493
Fri Apr  9 05:12:31 2010 : Debug: 	locking = no
Fri Apr  9 05:12:31 2010 : Debug: 	log_packet_header = no
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Instantiating attr_filter.accounting_response
Fri Apr  9 05:12:31 2010 : Debug:   attr_filter attr_filter.accounting_response {
Fri Apr  9 05:12:31 2010 : Debug: 	attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
Fri Apr  9 05:12:31 2010 : Debug: 	key = "%{User-Name}"
Fri Apr  9 05:12:31 2010 : Debug:   }
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking session {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking post-proxy {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:  Module: Checking post-auth {...} for more modules to load
Fri Apr  9 05:12:31 2010 : Debug:  } # modules
Fri Apr  9 05:12:31 2010 : Debug: } # server
Fri Apr  9 05:12:31 2010 : Debug: radiusd: #### Opening IP addresses and Ports ####
Fri Apr  9 05:12:31 2010 : Debug: listen {
Fri Apr  9 05:12:31 2010 : Debug: 	type = "auth"
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = *
Fri Apr  9 05:12:31 2010 : Debug: 	port = 0
Fri Apr  9 05:12:31 2010 : Debug: }
Fri Apr  9 05:12:31 2010 : Debug: listen {
Fri Apr  9 05:12:31 2010 : Debug: 	type = "acct"
Fri Apr  9 05:12:31 2010 : Debug: 	ipaddr = *
Fri Apr  9 05:12:31 2010 : Debug: 	port = 0
Fri Apr  9 05:12:31 2010 : Debug: }
Fri Apr  9 05:12:31 2010 : Debug: listen {
Fri Apr  9 05:12:31 2010 : Debug: 	type = "control"
Fri Apr  9 05:12:31 2010 : Debug:  listen {
Fri Apr  9 05:12:31 2010 : Debug: 	socket = "/usr/local/var/run/radiusd/radiusd.sock"
Fri Apr  9 05:12:31 2010 : Debug:  }
Fri Apr  9 05:12:31 2010 : Debug: }
Fri Apr  9 05:12:31 2010 : Debug: Listening on authentication address * port 1812
Fri Apr  9 05:12:31 2010 : Debug: Listening on accounting address * port 1813
Fri Apr  9 05:12:31 2010 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock
Fri Apr  9 05:12:31 2010 : Debug: Listening on proxy address * port 1814
Fri Apr  9 05:12:31 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=0, length=81
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	EAP-Message = 0x0202000d017465737475736572
	Message-Authenticator = 0xf82eb7c92d2899fe68240f297804c282
Fri Apr  9 05:12:37 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:37 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:37 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:37 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:37 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:37 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:37 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:37 2010 : Info: [eap] EAP packet type response id 2 length 13
Fri Apr  9 05:12:37 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:37 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:37 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:37 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:37 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:37 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:37 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:37 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:37 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:37 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:37 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:37 2010 : Info: [eap] EAP Identity
Fri Apr  9 05:12:37 2010 : Info: [eap] processing type tls
Fri Apr  9 05:12:37 2010 : Info: [tls] Initiate
Fri Apr  9 05:12:37 2010 : Info: [tls] Start returned 1
Fri Apr  9 05:12:37 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 0 to 10.37.18.108 port 32774
	EAP-Message = 0x010300061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xfed7c105fed4d8b64698914296c27f73
Fri Apr  9 05:12:37 2010 : Info: Finished request 0.
Fri Apr  9 05:12:37 2010 : Debug: Going to the next request
Fri Apr  9 05:12:37 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=1, length=92
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	State = 0xfed7c105fed4d8b64698914296c27f73
	EAP-Message = 0x020300060304
	Message-Authenticator = 0xee94d16288c018545f9ff35481568248
Fri Apr  9 05:12:38 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:38 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:38 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:38 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:38 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:38 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:38 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:38 2010 : Info: [eap] EAP packet type response id 3 length 6
Fri Apr  9 05:12:38 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:38 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:38 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:38 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:38 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:38 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:38 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:38 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:38 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:38 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:38 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:38 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:38 2010 : Info: [eap] EAP NAK
Fri Apr  9 05:12:38 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr  9 05:12:38 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:38 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr  9 05:12:38 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 1 to 10.37.18.108 port 32774
	EAP-Message = 0x0104001604107c7195033951c3050c98f0e6d4a3dee6
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xfed7c105ffd3c5b64698914296c27f73
Fri Apr  9 05:12:38 2010 : Info: Finished request 1.
Fri Apr  9 05:12:38 2010 : Debug: Going to the next request
Fri Apr  9 05:12:38 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=2, length=116
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	State = 0xfed7c105ffd3c5b64698914296c27f73
	EAP-Message = 0x0204001e04102adeab76fb6cc27d3f67e4c5e6b2180e7465737475736572
	Message-Authenticator = 0xe6a2a2ae18f6d892c8f9cb30820a43a2
Fri Apr  9 05:12:38 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:38 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:38 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:38 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:38 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:38 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:38 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:38 2010 : Info: [eap] EAP packet type response id 4 length 30
Fri Apr  9 05:12:38 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:38 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:38 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:38 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:38 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:38 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:38 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:38 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:38 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:38 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:38 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:38 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:38 2010 : Info: [eap] EAP/md5
Fri Apr  9 05:12:38 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:38 2010 : Info: [eap] Freeing handler
Fri Apr  9 05:12:38 2010 : Info: ++[eap] returns ok
Fri Apr  9 05:12:38 2010 : Info: +- entering group post-auth {...}
Fri Apr  9 05:12:38 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 2 to 10.37.18.108 port 32774
	EAP-Message = 0x03040004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "testuser"
Fri Apr  9 05:12:38 2010 : Info: Finished request 2.
Fri Apr  9 05:12:38 2010 : Debug: Going to the next request
Fri Apr  9 05:12:38 2010 : Debug: Waking up in 4.4 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=3, length=81
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	EAP-Message = 0x0202000d017465737475736572
	Message-Authenticator = 0xd6e2ecc872ece2b5224619802824b104
Fri Apr  9 05:12:39 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:39 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:39 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:39 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:39 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:39 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:39 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:39 2010 : Info: [eap] EAP packet type response id 2 length 13
Fri Apr  9 05:12:39 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:39 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:39 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:39 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:39 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:39 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:39 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:39 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:39 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:39 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:39 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:39 2010 : Info: [eap] EAP Identity
Fri Apr  9 05:12:39 2010 : Info: [eap] processing type tls
Fri Apr  9 05:12:39 2010 : Info: [tls] Initiate
Fri Apr  9 05:12:39 2010 : Info: [tls] Start returned 1
Fri Apr  9 05:12:39 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 3 to 10.37.18.108 port 32774
	EAP-Message = 0x010300061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x6940fc336943e5749244849618765ae0
Fri Apr  9 05:12:39 2010 : Info: Finished request 3.
Fri Apr  9 05:12:39 2010 : Debug: Going to the next request
Fri Apr  9 05:12:39 2010 : Debug: Waking up in 2.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=4, length=92
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	State = 0x6940fc336943e5749244849618765ae0
	EAP-Message = 0x020300060304
	Message-Authenticator = 0x5b0f995330bef6938ced07dd3e4d3565
Fri Apr  9 05:12:40 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:40 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:40 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:40 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:40 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:40 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:40 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:40 2010 : Info: [eap] EAP packet type response id 3 length 6
Fri Apr  9 05:12:40 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:40 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:40 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:40 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:40 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:40 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:40 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:40 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:40 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:40 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:40 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:40 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:40 2010 : Info: [eap] EAP NAK
Fri Apr  9 05:12:40 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr  9 05:12:40 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:40 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr  9 05:12:40 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 4 to 10.37.18.108 port 32774
	EAP-Message = 0x01040016041066115a556c837ff8ce3092b7d21e41ab
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x6940fc336844f8749244849618765ae0
Fri Apr  9 05:12:40 2010 : Info: Finished request 4.
Fri Apr  9 05:12:40 2010 : Debug: Going to the next request
Fri Apr  9 05:12:40 2010 : Debug: Waking up in 2.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=5, length=116
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	State = 0x6940fc336844f8749244849618765ae0
	EAP-Message = 0x0204001e04108fcc0815933f7ca514870db8cfd8675a7465737475736572
	Message-Authenticator = 0xe2505cf1ecaa4db6be0b1e17f0782134
Fri Apr  9 05:12:40 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:40 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:40 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:40 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:40 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:40 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:40 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:40 2010 : Info: [eap] EAP packet type response id 4 length 30
Fri Apr  9 05:12:40 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:40 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:40 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:40 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:40 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:40 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:40 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:40 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:40 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:40 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:40 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:40 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:40 2010 : Info: [eap] EAP/md5
Fri Apr  9 05:12:40 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:40 2010 : Info: [eap] Freeing handler
Fri Apr  9 05:12:40 2010 : Info: ++[eap] returns ok
Fri Apr  9 05:12:40 2010 : Info: +- entering group post-auth {...}
Fri Apr  9 05:12:40 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 5 to 10.37.18.108 port 32774
	EAP-Message = 0x03040004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "testuser"
Fri Apr  9 05:12:40 2010 : Info: Finished request 5.
Fri Apr  9 05:12:40 2010 : Debug: Going to the next request
Fri Apr  9 05:12:40 2010 : Debug: Waking up in 2.4 seconds.
Fri Apr  9 05:12:42 2010 : Info: Cleaning up request 0 ID 0 with timestamp +6
Fri Apr  9 05:12:42 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:12:43 2010 : Info: Cleaning up request 1 ID 1 with timestamp +7
Fri Apr  9 05:12:43 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:12:43 2010 : Info: Cleaning up request 2 ID 2 with timestamp +7
Fri Apr  9 05:12:43 2010 : Debug: Waking up in 1.4 seconds.
Fri Apr  9 05:12:44 2010 : Info: Cleaning up request 3 ID 3 with timestamp +8
Fri Apr  9 05:12:44 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:12:45 2010 : Info: Cleaning up request 4 ID 4 with timestamp +9
Fri Apr  9 05:12:45 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:12:45 2010 : Info: Cleaning up request 5 ID 5 with timestamp +9
Fri Apr  9 05:12:45 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=6, length=81
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	EAP-Message = 0x0201000d017465737475736572
	Message-Authenticator = 0xc7f0609eff6b7fd2dec8109a5348db92
Fri Apr  9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP packet type response id 1 length 13
Fri Apr  9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP Identity
Fri Apr  9 05:12:56 2010 : Info: [eap] processing type tls
Fri Apr  9 05:12:56 2010 : Info: [tls] Initiate
Fri Apr  9 05:12:56 2010 : Info: [tls] Start returned 1
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 6 to 10.37.18.108 port 32774
	EAP-Message = 0x010200061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xfda61154fda408aa4e5f772b926dcec0
Fri Apr  9 05:12:56 2010 : Info: Finished request 6.
Fri Apr  9 05:12:56 2010 : Debug: Going to the next request
Fri Apr  9 05:12:56 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=7, length=81
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	EAP-Message = 0x0201000d017465737475736572
	Message-Authenticator = 0x1ac2eed0281f511c36e8646f9ecd0eb3
Fri Apr  9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP packet type response id 1 length 13
Fri Apr  9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP Identity
Fri Apr  9 05:12:56 2010 : Info: [eap] processing type tls
Fri Apr  9 05:12:56 2010 : Info: [tls] Initiate
Fri Apr  9 05:12:56 2010 : Info: [tls] Start returned 1
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 7 to 10.37.18.108 port 32774
	EAP-Message = 0x010200061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
Fri Apr  9 05:12:56 2010 : Info: Finished request 7.
Fri Apr  9 05:12:56 2010 : Debug: Going to the next request
Fri Apr  9 05:12:56 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=8, length=92
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
	EAP-Message = 0x020200060304
	Message-Authenticator = 0xa8beb5bd658bce6a9076f7e27eba308f
Fri Apr  9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP packet type response id 2 length 6
Fri Apr  9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:56 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP NAK
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr  9 05:12:56 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:56 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 8 to 10.37.18.108 port 32774
	EAP-Message = 0x0103001604108f152f3420a03e075ce69c869cca4624
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x9adb6d8e9bd8698f58d1c4737f9f229b
Fri Apr  9 05:12:56 2010 : Info: Finished request 8.
Fri Apr  9 05:12:56 2010 : Debug: Going to the next request
Fri Apr  9 05:12:56 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=9, length=92
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	State = 0x9adb6d8e9ad9748f58d1c4737f9f229b
	EAP-Message = 0x020200060304
	Message-Authenticator = 0x7cd0fe2d39f50ba97736d0d7c90508a1
Fri Apr  9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP packet type response id 2 length 6
Fri Apr  9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:56 2010 : Error: rlm_eap: No EAP session matching the State variable.
Fri Apr  9 05:12:56 2010 : Info: [eap] Either EAP-request timed out OR EAP-response to an unknown EAP-request
Fri Apr  9 05:12:56 2010 : Info: [eap] Failed in handler
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns invalid
Fri Apr  9 05:12:56 2010 : Info: Failed to authenticate the user.
Fri Apr  9 05:12:56 2010 : Info: Using Post-Auth-Type Reject
Fri Apr  9 05:12:56 2010 : Info: +- entering group REJECT {...}
Fri Apr  9 05:12:56 2010 : Info: [attr_filter.access_reject] 	expand: %{User-Name} -> testuser
Fri Apr  9 05:12:56 2010 : Debug:  attr_filter: Matched entry DEFAULT at line 11
Fri Apr  9 05:12:56 2010 : Info: ++[attr_filter.access_reject] returns updated
Fri Apr  9 05:12:56 2010 : Info: Delaying reject of request 9 for 1 seconds
Fri Apr  9 05:12:56 2010 : Debug: Going to the next request
Fri Apr  9 05:12:56 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=10, length=116
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406913537
	State = 0x9adb6d8e9bd8698f58d1c4737f9f229b
	EAP-Message = 0x0203001e041067c814ba64a55fa3e62a6b6c3863c7717465737475736572
	Message-Authenticator = 0xf2482c4ffa128045ef37b191ad60366f
Fri Apr  9 05:12:56 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:12:56 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:12:56 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:12:56 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:12:56 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP packet type response id 3 length 30
Fri Apr  9 05:12:56 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:12:56 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:12:56 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:12:56 2010 : Info: ++[files] returns ok
Fri Apr  9 05:12:56 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:12:56 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:12:56 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:12:56 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:12:56 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:12:56 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:12:56 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:12:56 2010 : Info: [eap] EAP/md5
Fri Apr  9 05:12:56 2010 : Info: [eap] processing type md5
Fri Apr  9 05:12:56 2010 : Info: [eap] Freeing handler
Fri Apr  9 05:12:56 2010 : Info: ++[eap] returns ok
Fri Apr  9 05:12:56 2010 : Info: +- entering group post-auth {...}
Fri Apr  9 05:12:56 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 10 to 10.37.18.108 port 32774
	EAP-Message = 0x03030004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "testuser"
Fri Apr  9 05:12:56 2010 : Info: Finished request 10.
Fri Apr  9 05:12:56 2010 : Debug: Going to the next request
Fri Apr  9 05:12:56 2010 : Debug: Waking up in 0.7 seconds.
Fri Apr  9 05:12:57 2010 : Info: Sending delayed reject for request 9
Sending Access-Reject of id 9 to 10.37.18.108 port 32774
Fri Apr  9 05:12:57 2010 : Debug: Waking up in 3.7 seconds.
Fri Apr  9 05:13:01 2010 : Info: Cleaning up request 6 ID 6 with timestamp +25
Fri Apr  9 05:13:01 2010 : Info: Cleaning up request 7 ID 7 with timestamp +25
Fri Apr  9 05:13:01 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:13:01 2010 : Info: Cleaning up request 8 ID 8 with timestamp +25
Fri Apr  9 05:13:01 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:13:01 2010 : Info: Cleaning up request 10 ID 10 with timestamp +25
Fri Apr  9 05:13:01 2010 : Debug: Waking up in 0.7 seconds.
Fri Apr  9 05:13:02 2010 : Info: Cleaning up request 9 ID 9 with timestamp +25
Fri Apr  9 05:13:02 2010 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=11, length=81
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	EAP-Message = 0x0204000d017465737475736572
	Message-Authenticator = 0xea32d9f24d334b6e71a403bb64e806af
Fri Apr  9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP packet type response id 4 length 13
Fri Apr  9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP Identity
Fri Apr  9 05:13:30 2010 : Info: [eap] processing type tls
Fri Apr  9 05:13:30 2010 : Info: [tls] Initiate
Fri Apr  9 05:13:30 2010 : Info: [tls] Start returned 1
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 11 to 10.37.18.108 port 32774
	EAP-Message = 0x010500061920
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x6c90013e6c9518adc200fb210d4c749a
Fri Apr  9 05:13:30 2010 : Info: Finished request 11.
Fri Apr  9 05:13:30 2010 : Debug: Going to the next request
Fri Apr  9 05:13:30 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=12, length=92
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	State = 0x6c90013e6c9518adc200fb210d4c749a
	EAP-Message = 0x020500060304
	Message-Authenticator = 0x609a7f9e553920fe0987403c2933723a
Fri Apr  9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP packet type response id 5 length 6
Fri Apr  9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:13:30 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP NAK
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP-NAK asked for EAP-Type/md5
Fri Apr  9 05:13:30 2010 : Info: [eap] processing type md5
Fri Apr  9 05:13:30 2010 : Debug: rlm_eap_md5: Issuing Challenge
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns handled
Sending Access-Challenge of id 12 to 10.37.18.108 port 32774
	EAP-Message = 0x0106001604106101f5a6ce9f14a96f0889a50307a6be
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x6c90013e6d9605adc200fb210d4c749a
Fri Apr  9 05:13:30 2010 : Info: Finished request 12.
Fri Apr  9 05:13:30 2010 : Debug: Going to the next request
Fri Apr  9 05:13:30 2010 : Debug: Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.37.18.108 port 32774, id=13, length=116
	User-Name = "testuser"
	Framed-MTU = 1000
	NAS-IP-Address = 10.37.18.108
	NAS-Port = 406848000
	State = 0x6c90013e6d9605adc200fb210d4c749a
	EAP-Message = 0x0206001e04105760a2073c5b4976e7bcc1dd2b83dee27465737475736572
	Message-Authenticator = 0x45df310f4d4aa4c0bfbcae5756e74ad9
Fri Apr  9 05:13:30 2010 : Info: +- entering group authorize {...}
Fri Apr  9 05:13:30 2010 : Info: ++[preprocess] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[chap] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[mschap] returns noop
Fri Apr  9 05:13:30 2010 : Info: [suffix] No '@' in User-Name = "testuser", looking up realm NULL
Fri Apr  9 05:13:30 2010 : Info: [suffix] No such realm "NULL"
Fri Apr  9 05:13:30 2010 : Info: ++[suffix] returns noop
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP packet type response id 6 length 30
Fri Apr  9 05:13:30 2010 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns updated
Fri Apr  9 05:13:30 2010 : Info: ++[unix] returns notfound
Fri Apr  9 05:13:30 2010 : Info: [files] users: Matched entry testuser at line 205
Fri Apr  9 05:13:30 2010 : Info: ++[files] returns ok
Fri Apr  9 05:13:30 2010 : Info: ++[expiration] returns noop
Fri Apr  9 05:13:30 2010 : Info: ++[logintime] returns noop
Fri Apr  9 05:13:30 2010 : Info: [pap] Found existing Auth-Type, not changing it.
Fri Apr  9 05:13:30 2010 : Info: ++[pap] returns noop
Fri Apr  9 05:13:30 2010 : Info: Found Auth-Type = EAP
Fri Apr  9 05:13:30 2010 : Info: +- entering group authenticate {...}
Fri Apr  9 05:13:30 2010 : Info: [eap] Request found, released from the list
Fri Apr  9 05:13:30 2010 : Info: [eap] EAP/md5
Fri Apr  9 05:13:30 2010 : Info: [eap] processing type md5
Fri Apr  9 05:13:30 2010 : Info: [eap] Freeing handler
Fri Apr  9 05:13:30 2010 : Info: ++[eap] returns ok
Fri Apr  9 05:13:30 2010 : Info: +- entering group post-auth {...}
Fri Apr  9 05:13:30 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 13 to 10.37.18.108 port 32774
	EAP-Message = 0x03060004
	Message-Authenticator = 0x00000000000000000000000000000000
	User-Name = "testuser"
Fri Apr  9 05:13:30 2010 : Info: Finished request 13.
Fri Apr  9 05:13:30 2010 : Debug: Going to the next request
Fri Apr  9 05:13:30 2010 : Debug: Waking up in 4.4 seconds.
Fri Apr  9 05:13:35 2010 : Info: Cleaning up request 11 ID 11 with timestamp +59
Fri Apr  9 05:13:35 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:13:35 2010 : Info: Cleaning up request 12 ID 12 with timestamp +59
Fri Apr  9 05:13:35 2010 : Debug: Waking up in 0.2 seconds.
Fri Apr  9 05:13:35 2010 : Info: Cleaning up request 13 ID 13 with timestamp +59
Fri Apr  9 05:13:35 2010 : Debug: Ready to process requests.