Problem with EAP/TLS and XP SP2

Hal Pomeranz hal at deer-run.com
Thu Nov 3 06:22:55 CET 2005


Radius Server: Freeradius 1.0.5 on Solaris 8 (Sparc)
Client:        Windows XP (SP2), Intel PRO/Wireless 2915 (a/b/g)
Access Point:  DLink DI-784

I'm having trouble getting my laptop (running Windows XP SP2) to
authenticate to my access point using EAP/TLS.  XP shows the wireless
interface hung forever in "Attempting to authenticate" state.  I've
been beating my head against this all day without success, although I
think I'm close and just missing something stupid and obvious.

In the debugging log from "radiusd -X" below, I can see my laptop
communicating with the radius server.  I'm definitely seeing the
correct username ("HalPomeranz") from the certificate I installed
on the laptop.  The radius server is finding the username entry
in my "users" file.  The only thing that looks like an error is
the lines that read:

  rlm_eap_tls: >>> TLS 1.0 Handshake [length 005e], CertificateRequest  
    TLS_accept: SSLv3 write certificate request A 
    TLS_accept: SSLv3 flush data 
    TLS_accept:error in SSLv3 read client certificate A 

I Googled a bit for this error message and turned up some mailing list
traffic describing similar problems, but no solutions.  Perhaps this
is a red herring, however.

Note that I am successfully using this same radius server to
authenticate some older clients which use LEAP to connect via a
different access point, so I'm thinking my radius config is basically
sound.

Does anybody have any suggestions for how to resolve my problem?
Anybody seen anything like this before?  Thanks in advance...

-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-
Hal Pomeranz, Founder/CEO      Deer Run Associates      hal at deer-run.com
    Network Connectivity and Security, Systems Management, Training
-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-

Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /var/freeradius/etc/raddb/proxy.conf
Config:   including file: /var/freeradius/etc/raddb/clients.conf
Config:   including file: /var/freeradius/etc/raddb/snmp.conf
Config:   including file: /var/freeradius/etc/raddb/eap.conf
Config:   including file: /var/freeradius/etc/raddb/sql.conf
 main: prefix = "/var/freeradius"
 main: localstatedir = "/var/freeradius/var"
 main: logdir = "/var/freeradius/var/log/radius"
 main: libdir = "/var/freeradius/lib"
 main: radacctdir = "/var/freeradius/var/log/radius/radacct"
 main: hostname_lookups = no
 main: max_request_time = 30
 main: cleanup_delay = 5
 main: max_requests = 1024
 main: delete_blocked_requests = 0
 main: port = 1812
 main: allow_core_dumps = no
 main: log_stripped_names = no
 main: log_file = "/var/freeradius/var/log/radius/radius.log"
 main: log_auth = no
 main: log_auth_badpass = no
 main: log_auth_goodpass = no
 main: pidfile = "/var/freeradius/var/run/radiusd/radiusd.pid"
 main: user = "radiusd"
 main: group = "radiusd"
 main: usercollide = no
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/var/freeradius/sbin/checkrad"
 main: proxy_requests = yes
 proxy: retry_delay = 5
 proxy: retry_count = 3
 proxy: synchronous = no
 proxy: default_fallback = yes
 proxy: dead_time = 120
 proxy: post_proxy_authorize = yes
 proxy: wake_all_if_all_dead = no
 security: max_attributes = 200
 security: reject_delay = 1
 security: status_server = no
 main: debug_level = 0
read_config_files:  reading dictionary
read_config_files:  reading naslist
Using deprecated naslist file.  Support for this will go away soon.
read_config_files:  reading clients
read_config_files:  reading realms
radiusd:  entering modules setup
Module: Library search path is /var/freeradius/lib
Module: Loaded exec 
 exec: wait = yes
 exec: program = "(null)"
 exec: input_pairs = "request"
 exec: output_pairs = "(null)"
 exec: packet_type = "(null)"
rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Module: Instantiated exec (exec) 
Module: Loaded expr 
Module: Instantiated expr (expr) 
Module: Loaded PAP 
 pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap) 
Module: Loaded CHAP 
Module: Instantiated chap (chap) 
Module: Loaded MS-CHAP 
 mschap: use_mppe = yes
 mschap: require_encryption = no
 mschap: require_strong = no
 mschap: with_ntdomain_hack = no
 mschap: passwd = "(null)"
 mschap: authtype = "MS-CHAP"
 mschap: ntlm_auth = "(null)"
Module: Instantiated mschap (mschap) 
Module: Loaded System 
 unix: cache = no
 unix: passwd = "(null)"
 unix: shadow = "(null)"
 unix: group = "(null)"
 unix: radwtmp = "/var/freeradius/var/log/radius/radwtmp"
 unix: usegroup = no
 unix: cache_reload = 600
Module: Instantiated unix (unix) 
Module: Loaded eap 
 eap: default_eap_type = "tls"
 eap: timer_expire = 60
 eap: ignore_unknown_eap_types = no
 eap: cisco_accounting_username_bug = no
rlm_eap: Loaded and initialized type md5
rlm_eap: Loaded and initialized type leap
 gtc: challenge = "Password: "
 gtc: auth_type = "PAP"
rlm_eap: Loaded and initialized type gtc
 tls: rsa_key_exchange = no
 tls: dh_key_exchange = yes
 tls: rsa_key_length = 512
 tls: dh_key_length = 512
 tls: verify_depth = 0
 tls: CA_path = "(null)"
 tls: pem_file_type = yes
 tls: private_key_file = "/var/freeradius/etc/raddb/certs/server_key.pem"
 tls: certificate_file = "/var/freeradius/etc/raddb/certs/server_cert.pem"
 tls: CA_file = "/var/freeradius/etc/raddb/certs/cacert.pem"
 tls: private_key_password = ""
 tls: dh_file = "/var/freeradius/etc/raddb/certs/dh"
 tls: random_file = "/var/freeradius/etc/raddb/certs/random"
 tls: fragment_size = 1024
 tls: include_length = yes
 tls: check_crl = yes
 tls: check_cert_cn = "%{User-Name}"
rlm_eap: Loaded and initialized type tls
 peap: default_eap_type = "mschapv2"
 peap: copy_request_to_tunnel = no
 peap: use_tunneled_reply = no
 peap: proxy_tunneled_request_as_eap = yes
rlm_eap: Loaded and initialized type peap
 mschapv2: with_ntdomain_hack = no
rlm_eap: Loaded and initialized type mschapv2
Module: Instantiated eap (eap) 
Module: Loaded preprocess 
 preprocess: huntgroups = "/var/freeradius/etc/raddb/huntgroups"
 preprocess: hints = "/var/freeradius/etc/raddb/hints"
 preprocess: with_ascend_hack = no
 preprocess: ascend_channels_per_line = 23
 preprocess: with_ntdomain_hack = no
 preprocess: with_specialix_jetstream_hack = no
 preprocess: with_cisco_vsa_hack = no
Module: Instantiated preprocess (preprocess) 
Module: Loaded realm 
 realm: format = "suffix"
 realm: delimiter = "@"
 realm: ignore_default = no
 realm: ignore_null = no
Module: Instantiated realm (suffix) 
Module: Loaded files 
 files: usersfile = "/var/freeradius/etc/raddb/users"
 files: acctusersfile = "/var/freeradius/etc/raddb/acct_users"
 files: preproxy_usersfile = "/var/freeradius/etc/raddb/preproxy_users"
 files: compat = "no"
Module: Instantiated files (files) 
Module: Loaded Acct-Unique-Session-Id 
 acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Module: Instantiated acct_unique (acct_unique) 
Module: Loaded detail 
 detail: detailfile = "/var/freeradius/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
 detail: detailperm = 384
 detail: dirperm = 493
 detail: locking = no
Module: Instantiated detail (detail) 
Module: Loaded radutmp 
 radutmp: filename = "/var/freeradius/var/log/radius/radutmp"
 radutmp: username = "%{User-Name}"
 radutmp: case_sensitive = yes
 radutmp: check_with_nas = yes
 radutmp: perm = 384
 radutmp: callerid = yes
Module: Instantiated radutmp (radutmp) 
Listening on authentication *:1812
Listening on accounting *:1813
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.100.4:1435, id=199, length=139
	User-Name = "HalPomeranz"
	NAS-IP-Address = 192.168.100.4
	NAS-Port = 0
	Called-Station-Id = "00-0D-88-C5-20-71"
	Calling-Station-Id = "00-15-00-0E-F4-F5"
	NAS-Identifier = "DI-784"
	Framed-MTU = 1380
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020100100148616c506f6d6572616e7a
	Message-Authenticator = 0xe476642b4d621276fdcfa07fc848c5d6
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
  modcall[authorize]: module "preprocess" returns ok for request 0
  modcall[authorize]: module "chap" returns noop for request 0
  modcall[authorize]: module "mschap" returns noop for request 0
    rlm_realm: No '@' in User-Name = "HalPomeranz", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 0
  rlm_eap: EAP packet type response id 1 length 16
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 0
    users: Matched entry HalPomeranz at line 101
  modcall[authorize]: module "files" returns ok for request 0
modcall: group authorize returns updated for request 0
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 0
  rlm_eap: EAP Identity
  rlm_eap: processing type tls
 rlm_eap_tls: Requiring client certificate
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 199 to 192.168.100.4:1435
	EAP-Message = 0x010200060d20
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf5332abd7af77b9911176ec9aa69e0e8
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.100.4:1435, id=200, length=221
	User-Name = "HalPomeranz"
	NAS-IP-Address = 192.168.100.4
	NAS-Port = 0
	Called-Station-Id = "00-0D-88-C5-20-71"
	Calling-Station-Id = "00-15-00-0E-F4-F5"
	NAS-Identifier = "DI-784"
	Framed-MTU = 1380
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020200500d800000004616030100410100003d030143696dabf9029fc190693ca4dc70364a394a56ff89289a020122f2e7346c770500001600040005000a000900640062000300060013001200630100
	State = 0xf5332abd7af77b9911176ec9aa69e0e8
	Message-Authenticator = 0x438ea47659b46e7e17bb9a54f66f02be
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
  modcall[authorize]: module "preprocess" returns ok for request 1
  modcall[authorize]: module "chap" returns noop for request 1
  modcall[authorize]: module "mschap" returns noop for request 1
    rlm_realm: No '@' in User-Name = "HalPomeranz", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 1
  rlm_eap: EAP packet type response id 2 length 80
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 1
    users: Matched entry HalPomeranz at line 101
  modcall[authorize]: module "files" returns ok for request 1
modcall: group authorize returns updated for request 1
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 1
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/tls
  rlm_eap: processing type tls
  rlm_eap_tls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11 
    (other): before/accept initialization 
    TLS_accept: before/accept initialization 
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello  
    TLS_accept: SSLv3 read client hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello  
    TLS_accept: SSLv3 write server hello A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0510], Certificate  
    TLS_accept: SSLv3 write certificate A 
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 005e], CertificateRequest  
    TLS_accept: SSLv3 write certificate request A 
    TLS_accept: SSLv3 flush data 
    TLS_accept:error in SSLv3 read client certificate A 
In SSL Handshake Phase 
In SSL Accept mode  
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 1
modcall: group authenticate returns handled for request 1
Sending Access-Challenge of id 200 to 192.168.100.4:1435
	EAP-Message = 0x0103040a0dc0000005c7160301004a02000046030143696da6a2b012e765aa3f113c4c1ed6e28c40f51807859cd4394962388ae6e0202f9cf584c484b68b3aa0eb66ee1d1edec787b87407a2bf043891da3dc798f42b00040016030105100b00050c00050900024730820243308201aca003020102020101300d06092a864886f70d0101040500304d310b3009060355040613025553310f300d060355040813064f7265676f6e310f300d06035504071306457567656e65311c301a060355040a1313446565722052756e204173736f636961746573301e170d3035313130323139323533385a170d3036313130323139323533385a3069310b300906
	EAP-Message = 0x0355040613025553310f300d060355040813064f7265676f6e310f300d06035504071306457567656e65311c301a060355040a1313446565722052756e204173736f636961746573311a301806035504031311646565722e646565722d72756e2e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100c0511b635bded2881c4db827a89c521fbcc5a06b435b4ad56cd1b9b8ad0e78815ef2bd5d1e60e7a4c7f6b1a154cde960cf5de365fdd2fa462b3b90934d252245e87996b4031326e118dc68f9c9f6e3efb08958ba388f7677c47ecbf35514a74f27926b6a39d7f452c9caa2fb9d98fd3bdde64c4aa8f1b81228f502d1
	EAP-Message = 0x117dcd5f0203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104050003818100243b1d366876ce82374e51d6e84e0a7e93a70558baad71a2a43ddc3602bc87df8c8d96fc2e903e1b68ae3bfdd5e1e8e1764d7d636d7bcdd0aa4a2f33598115ad1b6d90d43596654f4f956f26ad6cfc6d47330bc0d2a57e8e1998b9fc6da570c117a643bb699091f80f5aff0c44f6bb875ef27e0d79fbfda8ca01763debfff8960002bc308202b830820221a003020102020100300d06092a864886f70d0101040500304d310b3009060355040613025553310f300d060355040813064f7265676f6e310f300d0603
	EAP-Message = 0x5504071306457567656e65311c301a060355040a1313446565722052756e204173736f636961746573301e170d3035313130323139313931355a170d3036313130323139313931355a304d310b3009060355040613025553310f300d060355040813064f7265676f6e310f300d06035504071306457567656e65311c301a060355040a1313446565722052756e204173736f63696174657330819f300d06092a864886f70d010101050003818d0030818902818100c16d27eab105d0e179e6a58207dd1b7d0c1a5a64f761506275abebf495254f4e242f9d13926e56bfe0bb8d9130afca9287746c12c5eed4f0ae5233ecc412bba6693cf9fad4e1db0f
	EAP-Message = 0x4f4b39c0f47ed5293975a9448d479ca38fbddeef68e1
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0xf608c3c340e7dcd273e77d1ca5afd315
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.100.4:1435, id=201, length=147
	User-Name = "HalPomeranz"
	NAS-IP-Address = 192.168.100.4
	NAS-Port = 0
	Called-Station-Id = "00-0D-88-C5-20-71"
	Calling-Station-Id = "00-15-00-0E-F4-F5"
	NAS-Identifier = "DI-784"
	Framed-MTU = 1380
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020300060d00
	State = 0xf608c3c340e7dcd273e77d1ca5afd315
	Message-Authenticator = 0x399bf08221ad337dec5353e34d1f3f9e
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
  modcall[authorize]: module "preprocess" returns ok for request 2
  modcall[authorize]: module "chap" returns noop for request 2
  modcall[authorize]: module "mschap" returns noop for request 2
    rlm_realm: No '@' in User-Name = "HalPomeranz", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 2
  rlm_eap: EAP packet type response id 3 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 2
    users: Matched entry HalPomeranz at line 101
  modcall[authorize]: module "files" returns ok for request 2
modcall: group authorize returns updated for request 2
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 2
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/tls
  rlm_eap: processing type tls
  rlm_eap_tls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 2
modcall: group authenticate returns handled for request 2
Sending Access-Challenge of id 201 to 192.168.100.4:1435
	EAP-Message = 0x010401d10d80000005c709eeaeeb99893a248df35086a268947b61542d3988e761db738040976f08e84fd7830203010001a381a73081a4301d0603551d0e0416041400b41eff09bcce9ad9f1b04ba50419a7db44a7f030750603551d23046e306c801400b41eff09bcce9ad9f1b04ba50419a7db44a7f0a151a44f304d310b3009060355040613025553310f300d060355040813064f7265676f6e310f300d06035504071306457567656e65311c301a060355040a1313446565722052756e204173736f636961746573820100300c0603551d13040530030101ff300d06092a864886f70d010104050003818100b8ddea1e6f5851b78cca0feab23bd8
	EAP-Message = 0x9b7d268ab9250ccd7a7d720d6c2cf103477a6445773dca5be28fd44611b9e4a2a9a6331550fbad950e21fea1ff8e70a3d178c9d1ebf13b12cd80d6ce561be9699a922a722207d4950140bb0aeb3d8b3e22021a83c91948f1903b4eaedb66a1288837436871f1a57bda39f374a3fb8af28b160301005e0d0000560201020051004f304d310b3009060355040613025553310f300d060355040813064f7265676f6e310f300d06035504071306457567656e65311c301a060355040a1313446565722052756e204173736f6369617465730e000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x86870d983715d15f6919bdba762433c2
Finished request 2
Going to the next request
--- Walking the entire request list ---
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 192.168.100.4:1435, id=202, length=147
	User-Name = "HalPomeranz"
	NAS-IP-Address = 192.168.100.4
	NAS-Port = 0
	Called-Station-Id = "00-0D-88-C5-20-71"
	Calling-Station-Id = "00-15-00-0E-F4-F5"
	NAS-Identifier = "DI-784"
	Framed-MTU = 1380
	NAS-Port-Type = Wireless-802.11
	EAP-Message = 0x020400060d00
	State = 0x86870d983715d15f6919bdba762433c2
	Message-Authenticator = 0xeda680bdf69e5dd588260e1c36169581
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
  modcall[authorize]: module "preprocess" returns ok for request 3
  modcall[authorize]: module "chap" returns noop for request 3
  modcall[authorize]: module "mschap" returns noop for request 3
    rlm_realm: No '@' in User-Name = "HalPomeranz", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 3
  rlm_eap: EAP packet type response id 4 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 3
    users: Matched entry HalPomeranz at line 101
  modcall[authorize]: module "files" returns ok for request 3
modcall: group authorize returns updated for request 3
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 3
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/tls
  rlm_eap: processing type tls
  rlm_eap_tls: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1 
  eaptls_process returned 13 
  modcall[authenticate]: module "eap" returns handled for request 3
modcall: group authenticate returns handled for request 3
Sending Access-Challenge of id 202 to 192.168.100.4:1435
	EAP-Message = 0x0105000a0d8000000000
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x2b04eed7fe0be0ec28fbba826e52b47c
Finished request 3
Going to the next request
--- Walking the entire request list ---
Waking up in 4 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 199 with timestamp 43696da6
Cleaning up request 1 ID 200 with timestamp 43696da6
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 2 ID 201 with timestamp 43696da7
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 3 ID 202 with timestamp 43696da8
Nothing to do.  Sleeping until we see a request.



More information about the Freeradius-Users mailing list