EAP/TLS authentication timeout

4 Nov 2009

      Hi,

I'm trying to establish a EAP/TLS authentication. The certificates are
created by the freeradius scripts. rad_eap_test v0.22 is used for
testing. Somehow the authentication request runs into to timeout, but I
can't see what's wrong. Any suggestions ?

# ~/rad_eap_test -S testing123 -u wiedemj@edcllc.net -m IEEE8021X -e TLS
-H localhost -P 1812 -j client.pem -k client.pem -p hello -c timeout; 6
Sending RADIUS message to authentication server RADIUS message: code=1
(Access-Request) identifier=0 length=147
   Attribute 1 (User-Name) length=20
      Value: 'wiedemj@edcllc.net'
   Attribute 4 (NAS-IP-Address) length=6
      Value: 127.0.0.1
   Attribute 31 (Calling-Station-Id) length=19
      Value: '70-6F-6C-69-73-68'
   Attribute 12 (Framed-MTU) length=6
      Value: 1400
   Attribute 61 (NAS-Port-Type) length=6
      Value: 19
   Attribute 77 (Connect-Info) length=27
      Value: 'rad_eap_test + eapol_test'
   Attribute 79 (EAP-Message) length=25
      Value: 02 00 00 17 01 77 69 65 64 65 6d 6a 40 65 64 63 6c 6c 63 2e
6e 65 74
   Attribute 80 (Message-Authenticator) length=18
      Value: cb 31 3e 88 24 e8 1a 10 cc b4 d2 12 6e bf 8c 68 Received
RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=0
length=80
   Attribute 79 (EAP-Message) length=24
      Value: 01 01 00 16 04 10 89 18 38 04 bb 3d d5 df 53 ef 55 cb 64 5b
52 9b
   Attribute 80 (Message-Authenticator) length=18
      Value: d8 85 a6 2f e9 11 da 62 f9 a3 43 1b 04 21 70 90
   Attribute 24 (State) length=18
      Value: be 60 98 38 be 61 9c a1 ab 26 38 fa 49 90 77 88
  Copied RADIUS State Attribute
Sending RADIUS message to authentication server RADIUS message: code=1
(Access-Request) identifier=1 length=148
   Attribute 1 (User-Name) length=20
      Value: 'wiedemj@edcllc.net'
   Attribute 4 (NAS-IP-Address) length=6
      Value: 127.0.0.1
   Attribute 31 (Calling-Station-Id) length=19
      Value: '70-6F-6C-69-73-68'
   Attribute 12 (Framed-MTU) length=6
      Value: 1400
   Attribute 61 (NAS-Port-Type) length=6
      Value: 19
   Attribute 77 (Connect-Info) length=27
      Value: 'rad_eap_test + eapol_test'
   Attribute 79 (EAP-Message) length=8
      Value: 02 01 00 06 03 0d
   Attribute 24 (State) length=18
      Value: be 60 98 38 be 61 9c a1 ab 26 38 fa 49 90 77 88
   Attribute 80 (Message-Authenticator) length=18
      Value: e4 1a c5 34 14 71 94 0c 2b 7c 4b ad 9b 3f c6 ae Received
RADIUS message RADIUS message: code=11 (Access-Challenge) identifier=1
length=64
   Attribute 79 (EAP-Message) length=8
      Value: 01 02 00 06 0d 20
   Attribute 80 (Message-Authenticator) length=18
      Value: 55 fa ee 1b 05 ce 82 83 ed ea 1c 98 a6 0e 52 2d
   Attribute 24 (State) length=18
      Value: be 60 98 38 bf 62 95 a1 ab 26 38 fa 49 90 77 88
------------------------------------------------------------------------
------
FreeRADIUS Version 2.1.3, for host i486-pc-linux-gnu, built on Feb 25
2009 at 14:17:43 Starting - reading configuration files ...
group = freerad
user = freerad
including dictionary file /etc/freeradius/dictionary main {
	prefix = "/usr"
	localstatedir = "/var"
	logdir = "/var/log/freeradius"
	libdir = "/usr/lib/freeradius"
	radacctdir = "/var/log/freeradius/radacct"
	hostname_lookups = no
	max_request_time = 30
	cleanup_delay = 5
	max_requests = 1024
	allow_core_dumps = no
	pidfile = "/var/run/freeradius/freeradius.pid"
	checkrad = "/usr/sbin/checkrad"
	debug_level = 0
	proxy_requests = yes
 log {
	stripped_names = no
	auth = yes
	auth_badpass = yes
	auth_goodpass = yes
 }
 security {
	max_attributes = 200
	reject_delay = 1
	status_server = yes
 }
}

 client localhost {
	ipaddr = 127.0.0.1
	require_message_authenticator = no
	secret = "testing123"
	nastype = "other"
 }
radiusd: #### Loading Realms and Home Servers ####  proxy server {
	retry_delay = 5
	retry_count = 3
	default_fallback = no
	dead_time = 120
	wake_all_if_all_dead = no
 }

 home_server localhost {
	ipaddr = 127.0.0.1
	port = 1812
	type = "auth"
	secret = "testing123"
	response_window = 20
	max_outstanding = 65536
	zombie_period = 40
	status_check = "status-server"
	ping_interval = 30
	check_interval = 30
	num_answers_to_alive = 3
	num_pings_to_alive = 3
	revive_interval = 120
	status_check_timeout = 4
 }
 home_server_pool my_auth_failover {
	type = fail-over
	home_server = localhost
 }
 realm example.com {
	auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Instantiating modules ####  instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating exec
  exec {
	wait = no
	input_pairs = "request"
	shell_escape = yes
  }
 Module: Linked to module rlm_expr
 Module: Instantiating expr
 Module: Linked to module rlm_expiration
 Module: Instantiating expiration
  expiration {
	reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating logintime
  logintime {
	reply-message = "You are calling outside your allowed timespan
"
	minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers #### server inner-tunnel {
modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Linked to module rlm_pap
 Module: Instantiating pap
  pap {
	encryption_scheme = "auto"
	auto_header = yes
  }
 Module: Linked to module rlm_chap
 Module: Instantiating chap
 Module: Linked to module rlm_mschap
 Module: Instantiating mschap
  mschap {
	use_mppe = yes
	require_encryption = no
	require_strong = no
	with_ntdomain_hack = no
  }
 Module: Linked to module rlm_unix
 Module: Instantiating unix
  unix {
	radwtmp = "/var/log/freeradius/radwtmp"
  }
 Module: Linked to module rlm_eap
 Module: Instantiating eap
  eap {
	default_eap_type = "md5"
	timer_expire = 60
	ignore_unknown_eap_types = no
	cisco_accounting_username_bug = no
	max_sessions = 2048
  }
 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
	pem_file_type = yes
	private_key_file = "/etc/freeradius/certs/server.pem"
	certificate_file = "/etc/freeradius/certs/server.pem"
	CA_file = "/etc/freeradius/certs/ca.pem"
	private_key_password = "whatever"
	dh_file = "/etc/freeradius/certs/dh"
	random_file = "/etc/freeradius/certs/random"
	fragment_size = 1024
	include_length = yes
	check_crl = no
	check_cert_cn = "%{User-Name}"
	cipher_list = "DEFAULT"
    cache {
	enable = no
	lifetime = 24
	max_entries = 255
    }
   }
 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"
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
	default_eap_type = "mschapv2"
	copy_request_to_tunnel = no
	use_tunneled_reply = no
	proxy_tunneled_request_as_eap = yes
	virtual_server = "inner-tunnel"
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
	with_ntdomain_hack = no
   }
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
  realm suffix {
	format = "suffix"
	delimiter = "@"
	ignore_default = no
	ignore_null = no
  }
 Module: Linked to module rlm_files
 Module: Instantiating files
  files {
	usersfile = "/etc/freeradius/users"
	acctusersfile = "/etc/freeradius/acct_users"
	preproxy_usersfile = "/etc/freeradius/preproxy_users"
	compat = "no"
  }
[/etc/freeradius/users]:63 WARNING! Check item "Cleartext-Password"
found in reply item list for user "wiedemj@edcllc.net". 	This
attribute MUST go on the first line with the other check items
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating radutmp
  radutmp {
	filename = "/var/log/freeradius/radutmp"
	username = "%{User-Name}"
	case_sensitive = yes
	check_with_nas = yes
	perm = 384
	callerid = yes
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_attr_filter
 Module: Instantiating attr_filter.access_reject
  attr_filter attr_filter.access_reject {
	attrsfile = "/etc/freeradius/attrs.access_reject"
	key = "%{User-Name}"
  }
 }
}
 modules {
 Module: Checking authenticate {...} for more modules to load
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating preprocess
  preprocess {
	huntgroups = "/etc/freeradius/huntgroups"
	hints = "/etc/freeradius/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_detail
 Module: Instantiating auth_log
  detail auth_log {
	detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d"
	header = "%t"
	detailperm = 384
	dirperm = 493
	locking = no
	log_packet_header = no
  }
 Module: Instantiating DOT
  realm DOT {
	format = "suffix"
	delimiter = "."
	ignore_default = no
	ignore_null = no
  }
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
	key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
  }
 Module: Checking accounting {...} for more modules to load
 Module: Instantiating detail
  detail {
	detailfile =
"/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
	header = "%t"
	detailperm = 384
	dirperm = 493
	locking = no
	log_packet_header = no
  }
 Module: Instantiating attr_filter.accounting_response
  attr_filter attr_filter.accounting_response {
	attrsfile = "/etc/freeradius/attrs.accounting_response"
	key = "%{User-Name}"
  }
 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  }
radiusd: #### Opening IP addresses and Ports #### listen {
	type = "auth"
	ipaddr = *
	port = 0
}
listen {
	type = "acct"
	ipaddr = *
	port = 0
}
Listening on authentication address * port 1812 Listening on accounting
address * port 1813 Listening on proxy address * port 1814 Ready to
process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 44912, id=0,
length=147
	User-Name = "wiedemj@edcllc.net"
	NAS-IP-Address = 127.0.0.1
	Calling-Station-Id = "70-6F-6C-69-73-68"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "rad_eap_test + eapol_test"
	EAP-Message = 0x020000170177696564656d6a406564636c6c632e6e6574
	Message-Authenticator = 0x95336ebc6f464cec15da6ffd9b04bd3b
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] 	expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/auth-detail-20091103
[auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20091103
[auth_log] 	expand: %t -> Tue Nov  3 15:22:30 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[DOT] Looking up realm "net" for User-Name = "wiedemj@edcllc.net"
[DOT] No such realm "net"
++[DOT] returns noop
[suffix] Looking up realm "edcllc.net" for User-Name =
"wiedemj@edcllc.net"
[suffix] No such realm "edcllc.net"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 23 [eap] No EAP Start,
assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry wiedemj@edcllc.net at line 63
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 44912
	EAP-Message = 0x0101001604104abafec88ced95d38fea53aa31dd5856
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xa14c8326a14d873428b7c5da9617a833
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 44912, id=1,
length=148
	User-Name = "wiedemj@edcllc.net"
	NAS-IP-Address = 127.0.0.1
	Calling-Station-Id = "70-6F-6C-69-73-68"
	Framed-MTU = 1400
	NAS-Port-Type = Wireless-802.11
	Connect-Info = "rad_eap_test + eapol_test"
	EAP-Message = 0x02010006030d
	State = 0xa14c8326a14d873428b7c5da9617a833
	Message-Authenticator = 0xa2a501fa232db3c9eea5e82e3800f17e
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log] 	expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/127.0.0.1/auth-detail-20091103
[auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20091103
[auth_log] 	expand: %t -> Tue Nov  3 15:22:30 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[DOT] Looking up realm "net" for User-Name = "wiedemj@edcllc.net"
[DOT] No such realm "net"
++[DOT] returns noop
[suffix] Looking up realm "edcllc.net" for User-Name =
"wiedemj@edcllc.net"
[suffix] No such realm "edcllc.net"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 6 [eap] No EAP Start,
assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry wiedemj@edcllc.net at line 63
++[files] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list [eap] EAP NAK [eap] EAP-NAK
asked for EAP-Type/tls [eap] processing type tls [tls] Requiring client
certificate [tls] Initiate [tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 1 to 127.0.0.1 port 44912
	EAP-Message = 0x010200060d20
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xa14c8326a04e8e3428b7c5da9617a833
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 0 with timestamp +12 Cleaning up request 1 ID 1
with timestamp +12 Ready to process requests.

Regards
Joerg

EAP/TLS authentication timeout

Wiedemann, Joerg