Re: Problem with EAP/TLS and XP SP2

10 Nov 2005

      ----- Original Message -----
From: "Hal Pomeranz" <hal@deer-run.com>
To: freeradius-users@lists.freeradius.org
Subject: Problem with EAP/TLS and XP SP2
Date: Wed, 2 Nov 2005 21:22:55 -0800
...
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@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.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- 
_______________________________________________

Search for businesses by name, location, or phone number.  -Lycos Yellow Pages

http://r.lycos.com/r/yp_emailfooter/http://yellowpages.lycos.com/default.asp...

Re: Problem with EAP/TLS and XP SP2

mahesh luhar