EAP issue

22 Aug 2012


      Guys I am having an issue with some older WiMax clients (sigh I know, I
know).  The client works on my original server but not the new one
installed.
Here is the problem area:
Found Auth-Type = MSCHAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group MS-CHAP {...}
[mschap] Creating challenge hash with username: 0010e7ea87f7@WiMax.com
[mschap] Told to do MS-CHAPv2 for 0010e7ea87f7@WiMax.com with NT-Password
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] returns reject
Failed to authenticate the user.
} # server inner-tunnel
[ttls] Got tunneled reply code 3
	Framed-Filter-Id := "BE_3M"
	MS-CHAP-Error = "xE=691 R=1"
[ttls] Got tunneled Access-Reject
[eap] Handler failed in EAP/ttls
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.

And the full debug:
FreeRADIUS Version 2.1.12, for host x86_64-unknown-linux-gnu, built on May
24 2012 at 15:11:34
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. 
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
PARTICULAR PURPOSE. 
You may redistribute copies of FreeRADIUS under the terms of the 
GNU General Public License v2. 
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/eap
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/krb5
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/ntlm_auth
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/dynamic_clients
including configuration file /etc/raddb/modules/ldap
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/sql
including configuration file /etc/raddb/sql/mysql/dialup.conf
including configuration file /etc/raddb/modules/soh
including configuration file /etc/raddb/modules/rediswho
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/redis
including configuration file /etc/raddb/modules/opendirectory
including configuration file /etc/raddb/modules/sqlippool
including configuration file /etc/raddb/sql/postgresql/ippool.conf
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/inner-tunnel
including configuration file /etc/raddb/sites-enabled/control-socket
including configuration file /etc/raddb/sites-enabled/default
main {
	allow_core_dumps = no
}
including dictionary file /etc/raddb/dictionary
main {
	name = "radiusd"
	prefix = "/"
	localstatedir = "//var"
	sbindir = "//sbin"
	logdir = "//var/log/radius"
	run_dir = "//var/run/radiusd"
	libdir = "//lib"
	radacctdir = "//var/log/radius/radacct"
	hostname_lookups = no
	max_request_time = 30
	cleanup_delay = 5
	max_requests = 1024
	pidfile = "//var/run/radiusd/radiusd.pid"
	checkrad = "//sbin/checkrad"
	debug_level = 0
	proxy_requests = yes
 log {
	stripped_names = no
	auth = no
	auth_badpass = no
	auth_goodpass = no
 }
 security {
	max_attributes = 200
	reject_delay = 1
	status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 realm WiMAX.com {
 }
radiusd: #### Loading Clients ####
 client localhost {
	ipaddr = 127.0.0.1
	require_message_authenticator = no
	secret = "testing123"
	nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating module "exec" from file /etc/raddb/modules/exec
  exec {
	wait = no
	input_pairs = "request"
	shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating module "expr" from file /etc/raddb/modules/expr
 Module: Linked to module rlm_expiration
 Module: Instantiating module "expiration" from file
/etc/raddb/modules/expiration
  expiration {
	reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating module "logintime" from file
/etc/raddb/modules/logintime
  logintime {
	reply-message = "You are calling outside your allowed timespan  "
	minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server { # from file /etc/raddb/radiusd.conf
 modules {
  Module: Creating Post-Auth-Type = REJECT
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_mschap
 Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap
  mschap {
	use_mppe = yes
	require_encryption = no
	require_strong = no
	with_ntdomain_hack = no
	allow_retry = yes
  }
 Module: Linked to module rlm_eap
 Module: Instantiating module "eap" from file /etc/raddb/modules/eap
  eap {
	default_eap_type = "md5"
	timer_expire = 60
	ignore_unknown_eap_types = no
	cisco_accounting_username_bug = no
	max_sessions = 4096
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
	challenge = "Password: "
	auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
	rsa_key_exchange = no
	dh_key_exchange = yes
	rsa_key_length = 512
	dh_key_length = 512
	verify_depth = 0
	CA_path = "/etc/raddb/certs"
	pem_file_type = yes
	private_key_file = "/etc/raddb/certs/server.pem"
	certificate_file = "/etc/raddb/certs/server.pem"
	CA_file = "/etc/raddb/certs/ca.pem"
	private_key_password = "whatever"
	dh_file = "/etc/raddb/certs/dh"
	random_file = "/etc/raddb/certs/random"
	fragment_size = 1024
	include_length = yes
	check_crl = no
	cipher_list = "DEFAULT"
	make_cert_command = "/etc/raddb/certs/bootstrap"
	ecdh_curve = "prime256v1"
    cache {
	enable = no
	lifetime = 24
	max_entries = 255
    }
    verify {
    }
    ocsp {
	enable = no
	override_cert_url = yes
	url = "http://127.0.0.1/ocsp/"
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
	default_eap_type = "md5"
	copy_request_to_tunnel = yes
	use_tunneled_reply = yes
	virtual_server = "inner-tunnel"
	include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
	default_eap_type = "mschapv2"
	copy_request_to_tunnel = yes
	use_tunneled_reply = yes
	proxy_tunneled_request_as_eap = yes
	virtual_server = "inner-tunnel"
	soh = no
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
	with_ntdomain_hack = no
	send_error = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating module "preprocess" from file
/etc/raddb/modules/preprocess
  preprocess {
	huntgroups = "/etc/raddb/huntgroups"
	hints = "/etc/raddb/hints"
	with_ascend_hack = no
	ascend_channels_per_line = 23
	with_ntdomain_hack = no
	with_specialix_jetstream_hack = no
	with_cisco_vsa_hack = no
	with_alvarion_vsa_hack = no
  }
 Module: Linked to module rlm_wimax
 Module: Instantiating module "wimax" from file /etc/raddb/modules/wimax
  wimax {
	delete_mppe_keys = yes
  }
 Module: Linked to module rlm_sql
 Module: Instantiating module "sql" from file /etc/raddb/modules/sql
  sql {
	driver = "rlm_sql_mysql"
	server = "localhost"
	port = ""
	login = "radius"
	password = "unl0ck"
	radius_db = "radius"
	read_groups = yes
	sqltrace = no
	sqltracefile = "//var/log/radius/sqltrace.sql"
	readclients = yes
	deletestalesessions = yes
	num_sql_socks = 5
	lifetime = 0
	max_queries = 0
	sql_user_name = "%{User-Name}"
	default_user_profile = ""
	nas_query = "SELECT id, nasname, shortname, type, secret, server
FROM nas"
	authorize_check_query = "SELECT id, username, attribute, value, op
FROM radcheck           WHERE username = '%{SQL-User-Name}'           ORDER
BY id"
	authorize_reply_query = "SELECT id, username, attribute, value, op
FROM radreply           WHERE username = '%{SQL-User-Name}'           ORDER
BY id"
	authorize_group_check_query = "SELECT id, groupname, attribute,
Value, op           FROM radgroupcheck           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
	authorize_group_reply_query = "SELECT id, groupname, attribute,
value, op           FROM radgroupreply           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
	accounting_onoff_query = "          UPDATE radacct           SET
acctstoptime       =  '%S',              acctsessiontime    =
unix_timestamp('%S') -
unix_timestamp(acctstarttime),              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
%{%{Acct-Delay-Time}:-0}           WHERE acctstoptime IS NULL           AND
nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime     <=
'%S'"
	accounting_update_query = "           UPDATE radacct           SET
framedipaddress = '%{Framed-IP-Address}',              acctsessiontime     =
'%{Acct-Session-Time}',              acctinputoctets     =
'%{%{Acct-Input-Gigawords}:-0}'  << 32 |
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets    =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}'           WHERE acctsessionid =
'%{Acct-Session-Id}'           AND username        = '%{SQL-User-Name}'
AND nasipaddress    = '%{NAS-IP-Address}'"
	accounting_update_query_alt = "           INSERT INTO radacct
(acctsessionid,    acctuniqueid,      username,              realm,
nasipaddress,      nasportid,              nasporttype,      acctstarttime,
acctsessiontime,              acctauthentic,    connectinfo_start,
acctinputoctets,              acctoutputoctets, calledstationid,
callingstationid,              servicetype,      framedprotocol,
framedipaddress,              acctstartdelay,   xascendsessionsvrkey)
VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}',              '%{NAS-Port-Type}',              DATE_SUB('%S',
INTERVAL (%{%{Acct-Session-Time}:-0} +
%{%{Acct-Delay-Time}:-0}) SECOND),
'%{Acct-Session-Time}',              '%{Acct-Authentic}', '',
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}'
<< 32 |              '%{%{Acct-Output-Octets}:-0}',
'%{Called-Station-Id}', '%{Calling-Station-Id}',
'%{Service-Type}', '%{Framed-Protocol}',
'%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
	accounting_start_query = "           INSERT INTO radacct
(acctsessionid,    acctuniqueid,     username,              realm,
nasipaddress,     nasportid,              nasporttype,      acctstarttime,
acctstoptime,              acctsessiontime,  acctauthentic,
connectinfo_start,              connectinfo_stop, acctinputoctets,
acctoutputoctets,              calledstationid,  callingstationid,
acctterminatecause,              servicetype,      framedprotocol,
framedipaddress,              acctstartdelay,   acctstopdelay,
xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}', '%S', NULL,              '0', '%{Acct-Authentic}',
'%{Connect-Info}',              '', '0', '0',
'%{Called-Station-Id}', '%{Calling-Station-Id}', '',
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
'%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
	accounting_start_query_alt = "           UPDATE radacct SET
acctstarttime     = '%S',              acctstartdelay    =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_start =
'%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'
AND username         = '%{SQL-User-Name}'           AND nasipaddress     =
'%{NAS-IP-Address}'"
	accounting_stop_query = "           UPDATE radacct SET
acctstoptime       = '%S',              acctsessiontime    =
'%{Acct-Session-Time}',              acctinputoctets    =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}',              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   =
'%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'
AND username          = '%{SQL-User-Name}'           AND nasipaddress      =
'%{NAS-IP-Address}'"
	accounting_stop_query_alt = "           INSERT INTO radacct
(acctsessionid, acctuniqueid, username,              realm, nasipaddress,
nasportid,              nasporttype, acctstarttime, acctstoptime,
acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop, acctinputoctets, acctoutputoctets,
calledstationid, callingstationid, acctterminatecause,
servicetype, framedprotocol, framedipaddress,              acctstartdelay,
acctstopdelay)           VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
'%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
'%{NAS-Port-Type}',              DATE_SUB('%S',                  INTERVAL
(%{%{Acct-Session-Time}:-0} +                  %{%{Acct-Delay-Time}:-0})
SECOND),              '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '',
'%{Connect-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}'
<< 32 |              '%{%{Acct-Output-Octets}:-0}',
'%{Called-Station-Id}', '%{Calling-Station-Id}',
'%{Acct-Terminate-Cause}',              '%{Service-Type}',
'%{Framed-Protocol}', '%{Framed-IP-Address}',              '0',
'%{%{Acct-Delay-Time}:-0}')"
	group_membership_query = "SELECT groupname           FROM
radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER
BY priority"
	connect_failure_retry_delay = 60
	simul_count_query = ""
	simul_verify_query = "SELECT radacctid, acctsessionid, username,
nasipaddress, nasportid, framedipaddress,
callingstationid, framedprotocol                                FROM radacct
WHERE username = '%{SQL-User-Name}'                                AND
acctstoptime IS NULL"
	postauth_query = "INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
'%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
	safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius@localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): Processing generate_sql_clients
rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname,
shortname, type, secret, server FROM nas
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql (sql): Read entry
nasname=10.200.16.5,shortname=Extreme1,secret=unl0ck
rlm_sql (sql): Adding client 10.200.16.5 (Extreme1, server=<none>) to
clients list
rlm_sql (sql): Read entry nasname=10.0.2.2,shortname=ex-nat,secret=unlock
rlm_sql (sql): Adding client 10.0.2.2 (ex-nat, server=<none>) to clients
list
rlm_sql (sql): Read entry
nasname=10.200.40.7,shortname=TCreek1,secret=unl0ck
rlm_sql (sql): Adding client 10.200.40.7 (TCreek1, server=<none>) to clients
list
rlm_sql (sql): Read entry
nasname=10.200.40.8,shortname=TCreek2,secret=unl0ck
rlm_sql (sql): Adding client 10.200.40.8 (TCreek2, server=<none>) to clients
list
rlm_sql (sql): Read entry nasname=10.200.8.5,shortname=Hastings
Fairground,secret=unl0ck
rlm_sql (sql): Adding client 10.200.8.5 (Hastings Fairground, server=<none>)
to clients list
rlm_sql (sql): Read entry
nasname=10.200.40.6,shortname=TCreek3,secret=unl0ck
rlm_sql (sql): Adding client 10.200.40.6 (TCreek3, server=<none>) to clients
list
rlm_sql (sql): Read entry nasname=10.200.253.3,shortname=ASN2,secret=unl0ck
rlm_sql (sql): Adding client 10.200.253.3 (ASN2, server=<none>) to clients
list
rlm_sql (sql): Read entry nasname=10.200.253.2,shortname=ASN1,secret=unl0ck
rlm_sql (sql): Adding client 10.200.253.2 (ASN1, server=<none>) to clients
list
rlm_sql (sql): Read entry
nasname=64.186.196.161,shortname=wconnlab,secret=IRtesting4u
rlm_sql (sql): Adding client 64.186.196.161 (wconnlab, server=<none>) to
clients list
rlm_sql (sql): Read entry nasname=10.200.6.6,shortname=Hubble1,secret=unl0ck
rlm_sql (sql): Adding client 10.200.6.6 (Hubble1, server=<none>) to clients
list
rlm_sql (sql): Released sql socket id: 4
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating module "acct_unique" from file
/etc/raddb/modules/acct_unique
  acct_unique {
	key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
  }
 Module: Linked to module rlm_files
 Module: Instantiating module "files" from file /etc/raddb/modules/files
  files {
	usersfile = "/etc/raddb/users"
	acctusersfile = "/etc/raddb/acct_users"
	preproxy_usersfile = "/etc/raddb/preproxy_users"
	compat = "no"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating module "detail" from file /etc/raddb/modules/detail
  detail {
	detailfile =
"//var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
	header = "%t"
	detailperm = 384
	dirperm = 493
	locking = no
	log_packet_header = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating module "unix" from file /etc/raddb/modules/unix
  unix {
	radwtmp = "//var/log/radius/radwtmp"
  }
 Module: Linked to module rlm_radutmp
 Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp
  radutmp {
	filename = "//var/log/radius/radutmp"
	username = "%{User-Name}"
	case_sensitive = yes
	check_with_nas = yes
	perm = 384
	callerid = yes
  }
 Module: Linked to module rlm_sql_log
 Module: Instantiating module "sql_log" from file /etc/raddb/modules/sql_log
  sql_log {
	path = "//var/log/radius/radacct/sql-relay"
	Post-Auth = "INSERT INTO radpostauth                   	 (username,
pass, reply, authdate) VALUES                    	 ('%{User-Name}',
'%{User-Password:-Chap-Password}',         	 '%{reply:Packet-Type}',
'%S');"
	sql_user_name = "%{%{User-Name}:-DEFAULT}"
	utf8 = no
	safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating module "attr_filter.accounting_response" from file
/etc/raddb/modules/attr_filter
  attr_filter attr_filter.accounting_response {
	attrsfile = "/etc/raddb/attrs.accounting_response"
	key = "%{User-Name}"
	relaxed = no
  }
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Instantiating module "attr_filter.access_reject" from file
/etc/raddb/modules/attr_filter
  attr_filter attr_filter.access_reject {
	attrsfile = "/etc/raddb/attrs.access_reject"
	key = "%{User-Name}"
	relaxed = no
  }
 } # modules
} # server
server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating module "pap" from file /etc/raddb/modules/pap
  pap {
	encryption_scheme = "auto"
	auto_header = no
  }
 Module: Linked to module rlm_chap
 Module: Instantiating module "chap" from file /etc/raddb/modules/chap
 Module: Checking authorize {...} for more modules to load
 Module: Checking session {...} for more modules to load
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
	type = "auth"
	ipaddr = *
	port = 0
}
listen {
	type = "acct"
	ipaddr = *
	port = 0
}
listen {
	type = "control"
 listen {
	socket = "//var/run/radiusd/radiusd.sock"
 }
}
Listening on authentication address * port 1812
Listening on accounting address * port 1813
Listening on command file //var/run/radiusd/radiusd.sock
Listening on proxy address * port 1814
Ready to process requests.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=2,
length=240
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message =
0x02010035017b616d3d317d6165386361613266366266623837616438333838633639346132
3937643664334057694d61782e636f6d
	Message-Authenticator = 0x46c4b5efb6e3330bd3946c9d360bbbde
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 1 length 53
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql] 	expand: %{User-Name} ->
{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'
rlm_sql (sql): Reserving sql socket id: 3
[sql] 	expand: SELECT id, username, attribute, value, op           FROM
radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id
-> SELECT id, username, attribute, value, op           FROM radcheck
WHERE username = '=7Bam=3D1=7Dae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'
ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE
username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username =
'=7Bam=3D1=7Dae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'           ORDER BY
priority
rlm_sql (sql): Released sql socket id: 3
[sql] User {am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 2 to 10.200.6.6 port 1812
	EAP-Message = 0x0102001604104506f73942b4a0ad7c926d85b069bbab
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad5ce58f986d6caa1a2b094d48
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=240,
length=211
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message = 0x020200060315
	Message-Authenticator = 0xddd7ec6e66f4ad79cb68634b9032695c
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad5ce58f986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[sql] 	expand: %{User-Name} ->
{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com
[sql] sql_set_user escaped user -->
'{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'
rlm_sql (sql): Reserving sql socket id: 2
[sql] 	expand: SELECT id, username, attribute, value, op           FROM
radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id
-> SELECT id, username, attribute, value, op           FROM radcheck
WHERE username = '=7Bam=3D1=7Dae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'
ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE
username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username =
'=7Bam=3D1=7Dae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com'           ORDER BY
priority
rlm_sql (sql): Released sql socket id: 2
[sql] User {am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com not found
++[sql] returns notfound
++[expiration] returns noop
++[logintime] returns noop
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 240 to 10.200.6.6 port 1812
	EAP-Message = 0x010300061520
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad5de49e986d6caa1a2b094d48
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=174,
length=267
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message =
0x0203003e150016030100330100002f03010000011d8aae00fbebe12fc8495cf4f5dea9aeba
1727bab470cdd3b598d69209000008002f000a000500040100
	Message-Authenticator = 0x5982b52228ca69149faf290642f6693d
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad5de49e986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 3 length 62
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 0033], ClientHello  
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello  
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 085e], Certificate  
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate
A
In SSL Handshake Phase 
In SSL Accept mode  
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 174 to 10.200.6.6 port 1812
	EAP-Message =
0x0104040015c00000089b160301002a02000026030150349e215bfa580da4c744adca81194c
ac0044b986981ad1fa41abd442fd757b00002f00160301085e0b00085a0008570003a6308203
a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355
040613024652310f300d060355040813065261646975733112301006035504071309536f6d65
776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886
f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d457861
6d706c6520436572746966696361746520417574686f72697479
	EAP-Message =
0x301e170d3131303432383134323734355a170d3132303432373134323734355a307c310b30
09060355040613024652310f300d0603550408130652616469757331153013060355040a130c
4578616d706c6520496e632e312330210603550403131a4578616d706c652053657276657220
43657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d
706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a028201
0100c03f5810bfd5ff1d4515184e04164e9c372bc1788c20749414f1826da4e30273065db78c
57bd3d2113761396e856fd337993124ab38439a5542e74675071
	EAP-Message =
0x55a43f21a4ebeb29242c9375f5ff577a3042e4f63380ce81cfbbb9ac03d6df61255da3173a
09ce1c11d820108b082c9ec34b35acbf2696c9f2058e0065324f200c3253a03287902d62c030
dc4b99d4d891763511eccf37f560459b66553641aa06be8401b9fe4d314d23a9f1e239b05312
1201374b58af1a79cf18c4b9d40d52841b14cb91425dd84f715050b7f2c42817f37c75acfa91
77e6f61d8e1852051af2bd78cb7433c909574a409194f35dd5b155a1a7db5c90b96054f741cd
875cf6202d0203010001a317301530130603551d25040c300a06082b06010505070301300d06
092a864886f70d010104050003820101006b80565420e3e7f341
	EAP-Message =
0xa36b2bc3f0ad67dfc3a1649bdf32eb5b9c0210b9b9113e7e1bf0333fa500a0195ac0940f11
5a5b90e412384b5948121826f1cfe6e52006fe44bd39728d595f6b0140c345b2a326588008a4
b885d4defbd4fa2d4d9aac7c475f8ce56727ee39214c6d06b0faa7a959b0c01f00c0edc994f8
731c0285c380fce0187b49fb06495a4b31a57a97a399d282dd6a528631b62d60fd218470d570
a287746e000e8297d9a3874d53c5f2e87c7cfea92427e5e3ccc6a8e3a4cadbb1d3693a214953
e5c63e2f4641104351f2012a4263a2d6263756f55729e25ec0814538f6ae79e05c710be7eee4
249ba2705c561b1659503831428065750d2b45ab0004ab308204
	EAP-Message = 0xa73082038fa0030201020209
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad5ee39e986d6caa1a2b094d48
Finished request 2.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=61,
length=211
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message = 0x020400061500
	Message-Authenticator = 0x8ecea8d18f053b96e98c7131aff1bb8d
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad5ee39e986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 61 to 10.200.6.6 port 1812
	EAP-Message =
0x0105040015c00000089b00ae1f2dcb599a5930300d06092a864886f70d0101050500308193
310b3009060355040613024652310f300d060355040813065261646975733112301006035504
071309536f6d65776865726531153013060355040a130c4578616d706c6520496e632e312030
1e06092a864886f70d010901161161646d696e406578616d706c652e636f6d31263024060355
0403131d4578616d706c6520436572746966696361746520417574686f72697479301e170d31
31303432383134323734355a170d3132303432373134323734355a308193310b300906035504
0613024652310f300d0603550408130652616469757331123010
	EAP-Message =
0x06035504071309536f6d65776865726531153013060355040a130c4578616d706c6520496e
632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e636f6d3126
30240603550403131d4578616d706c6520436572746966696361746520417574686f72697479
30820122300d06092a864886f70d01010105000382010f003082010a02820101009f5c755631
c789945a7e1d1f9bb8a6c382b6dee817f668ea1fcb24e0061db17061af067f6f7493990b7a58
dd9fb42e0faaddd89a17d42fd081a48140f9b0193f25f57e84b190aa2d885566eadc6e383827
175545d417248c3c97f3f24be1e4a9131011c2008f1eb7506c31
	EAP-Message =
0x7c8a14eded911947f8c27049a517eefa15064859f7fff09c299e24f1804470a7a730b73442
4e5ff625d6760e9d1f36c4160effc001dfedcc0572f798c0563006e8c539253b723cb51b2f4b
2157c7678d5f37df8733727c31d48db7e13ea8e3a212fb77029296ecda8c035342241fc9dc6f
32fdcba2ceef8924a21d392eefdfd5396b96bb103d851850093f71532ec2c662404837bd0203
010001a381fb3081f8301d0603551d0e04160414199c57bca281cf9334ca702ab6a27ce0aeea
fa953081c80603551d230481c03081bd8014199c57bca281cf9334ca702ab6a27ce0aeeafa95
a18199a48196308193310b3009060355040613024652310f300d
	EAP-Message =
0x060355040813065261646975733112301006035504071309536f6d65776865726531153013
060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d01090116116164
6d696e406578616d706c652e636f6d312630240603550403131d4578616d706c652043657274
6966696361746520417574686f72697479820900ae1f2dcb599a5930300c0603551d13040530
030101ff300d06092a864886f70d0101050500038201010061e9a82ba0f55445f159f9095041
198e9284768ff0eba20437446acc342ce6b28d99b71a89b00449de410b807256f93b3f991468
126739aa08c95314d9d331e37ab99eafe1b822f91dc8d8aa8b1c
	EAP-Message = 0x1f10e90c295c9d991f0d1718
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad5fe29e986d6caa1a2b094d48
Finished request 3.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=31,
length=211
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message = 0x020500061500
	Message-Authenticator = 0x5caa24ace9ebad574567a1c7b2f99d18
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad5fe29e986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 31 to 10.200.6.6 port 1812
	EAP-Message =
0x010600b915800000089bdc8ddb5f1de53f04d51d34ac22c5552592ebf17751007e3634ee91
5e208c8d226c672bf1403f4bd50516997de46ad9cb619baa41b062c5214d430df469eb6ee1c0
a4e98a1c1265cc1915984377cb488690a19855ea5c22892b15e5028269dd319b556eb25e0455
26c01bc81c0b1f798ae6a94c0367002db543e5fe55dd0ca745a85f6c924998d8e3d1666c1601
0ff6010cf05f768c0c376bf9a421bb7facec0eb9218433376e16030100040e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad58e19e986d6caa1a2b094d48
Finished request 4.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=233,
length=539
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message =
0x0206014c150016030101061000010201006aa08bac60a5966ef61eb0ac489153e3e0b66ae6
411b4ad87eca37f8ca89cef32bec58e2eb4bc0281d3f7b421657886416e6dcef4a85f5cecb19
132aa5ff2b23bad397ae6c538a71ce0f626cd46550c05ade66c5b8339b1b5da0c1ed49d44a41
178e404c874a76e1ccf4fdda1bc3e4bcd03c8045c7e8703dea5fecaa76aad11df01ecff1ede1
529383e3d3231afcffa4a7807139729ead6974f9a8f6549a9027f97b06985a4313db8384452e
9463a2542e66ba5890cd3f1ec5f3d9f9a0ef88aab151a6974c17514f052364f9eecc76ba1e1e
c02a0e208ecacec085c6998f4d834b5a43cffd88461b1c0d5bbc
	EAP-Message =
0x36bb863ede7e5824aa0c846f12098b8d7f313959140301000101160301003051d88331ed31
814e949d069145191ca6f2f05822e593c3dbf7f9701c7f0d4620ebf153bcd96515938acddc1d
88d0e40f
	Message-Authenticator = 0x9cce8daf18ade07db6d49db0e9059ce7
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad58e19e986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 6 length 253
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange  
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 233 to 10.200.6.6 port 1812
	EAP-Message =
0x0107004515800000003b1403010001011603010030ad2ee345153bdb74da2e48b8bbea9d22
ff64e1c8ecfb70e819042cffc920b44457378d20d2cfbfc762e75ba4de14e702
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x5ce78bad59e09e986d6caa1a2b094d48
Finished request 5.
Going to the next request
Waking up in 4.4 seconds.
rad_recv: Access-Request packet from host 10.200.6.6 port 1812, id=152,
length=376
	User-Name = "{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com"
	EAP-Message =
0x020700ab150017030100a04e11f07d0ab4ea887ddc20c5af690c4bcd3b41e68dcd797ca7fe
ef75d823d078e69b43e9fd82a7acc55e3b7c875255785719223b2422493b296998e77e0df0ad
533eb6652c7aa0765062ae1daa5363c2815b56cb763932d6823c79e4d6ab0f941f716ecbfe2d
5b72f552c29893566957ce624486fa49881c197fe343b75270def1df697ba69804aa6f7bcc32
be6945c0287bec2383d570c8fa5414f0b7a560f3
	Message-Authenticator = 0xe9ddf6bda72ed4ac781128d29922ea10
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
	State = 0x5ce78bad59e09e986d6caa1a2b094d48
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
++[wimax] returns ok
[eap] EAP packet type response id 7 length 171
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] eaptls_process returned 7 
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
	User-Name = "0010e7eaa47c@WiMax.com"
	MS-CHAP-Challenge = 0xf88a050e58d2367e83aaec6302a59992
	MS-CHAP2-Response =
0xa700d3b94a45921d81527317b3d556afc97e0000000000000000df8a722f910d02aafdac89
7935457a3cc858651447526548
	FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
	User-Name = "0010e7eaa47c@WiMax.com"
	MS-CHAP-Challenge = 0xf88a050e58d2367e83aaec6302a59992
	MS-CHAP2-Response =
0xa700d3b94a45921d81527317b3d556afc97e0000000000000000df8a722f910d02aafdac89
7935457a3cc858651447526548
	FreeRADIUS-Proxied-To = 127.0.0.1
	NAS-IP-Address = 10.200.6.6
	Calling-Station-Id = "00-10-E7-EA-A4-7C"
	WiMAX-BS-Id = 0x010101012302
	NAS-Port-Type = Wireless-802.16
	Framed-MTU = 2000
	Service-Type = Framed-User
	WiMAX-GMT-Timezone-offset = 0
	WiMAX-Release = "1.0"
	WiMAX-Accounting-Capabilities = IP-Session-Based
	WiMAX-Hotlining-Capabilities = Hotline-Profile-Id
	WiMAX-Attr-1793 = 0x0000028a
server inner-tunnel {
# Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
+- entering group authorize {...}
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] returns ok
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[sql] 	expand: %{User-Name} -> 0010e7eaa47c@WiMax.com
[sql] sql_set_user escaped user --> '0010e7eaa47c@WiMax.com'
rlm_sql (sql): Reserving sql socket id: 1
[sql] 	expand: SELECT id, username, attribute, value, op           FROM
radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id
-> SELECT id, username, attribute, value, op           FROM radcheck
WHERE username = '0010e7eaa47c@WiMax.com'           ORDER BY id
[sql] User found in radcheck table
[sql] 	expand: SELECT id, username, attribute, value, op           FROM
radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id
-> SELECT id, username, attribute, value, op           FROM radreply
WHERE username = '0010e7eaa47c@WiMax.com'           ORDER BY id
[sql] 	expand: SELECT groupname           FROM radusergroup           WHERE
username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username =
'0010e7eaa47c@WiMax.com'           ORDER BY priority
[sql] 	expand: SELECT id, groupname, attribute,           Value, op
FROM radgroupcheck           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           Value, op
FROM radgroupcheck           WHERE groupname = 'BE_3M'           ORDER BY id
[sql] User found in group BE_3M
[sql] 	expand: SELECT id, groupname, attribute,           value, op
FROM radgroupreply           WHERE groupname = '%{Sql-Group}'
ORDER BY id -> SELECT id, groupname, attribute,           value, op
FROM radgroupreply           WHERE groupname = 'BE_3M'           ORDER BY id
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
Found Auth-Type = MSCHAP
# Executing group from file /etc/raddb/sites-enabled/inner-tunnel
+- entering group MS-CHAP {...}
[mschap] Creating challenge hash with username: 0010e7eaa47c@WiMax.com
[mschap] Told to do MS-CHAPv2 for 0010e7eaa47c@WiMax.com with NT-Password
[mschap] FAILED: MS-CHAP2-Response is incorrect
++[mschap] returns reject
Failed to authenticate the user.
} # server inner-tunnel
[ttls] Got tunneled reply code 3
	Framed-Filter-Id := "BE_3M"
	MS-CHAP-Error = "\247E=691 R=1"
[ttls] Got tunneled Access-Reject
[eap] Handler failed in EAP/ttls
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group REJECT {...}
[attr_filter.access_reject] 	expand: %{User-Name} ->
{am=1}ae8caa2f6bfb87ad8388c694a297d6d3@WiMax.com
attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 6 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.

EAP issue

David Peterson