problem with EAP-TLS

Fri Apr 6 21:20:58 CEST 2007

Hi,
i am using freeradius 1.1.3 and i have a problem with eap-tls, in full 
log it seems that it works, but windows xp client cannot connect
here is the log

Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /usr/local/etc/raddb/proxy.conf
Config:   including file: /usr/local/etc/raddb/clients.conf
Config:   including file: /usr/local/etc/raddb/snmp.conf
Config:   including file: /usr/local/etc/raddb/eap.conf
Config:   including file: /usr/local/etc/raddb/sql.conf
 main: prefix = "/usr/local"
 main: localstatedir = "/usr/local/var"
 main: logdir = "/usr/local/var/log/radius"
 main: libdir = "/usr/local/lib"
 main: radacctdir = "/usr/local/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 = 0
 main: allow_core_dumps = no
 main: log_stripped_names = yes
 main: log_file = "/usr/local/var/log/radius/radius.log"
 main: log_auth = yes
 main: log_auth_badpass = yes
 main: log_auth_goodpass = yes
 main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
 main: user = "(null)"
 main: group = "(null)"
 main: usercollide = no
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/usr/local/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 = no
 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 /usr/local/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: ntlm_auth = "(null)"
Module: Instantiated mschap (mschap)
Module: Loaded System
 unix: cache = no
 unix: passwd = "(null)"
 unix: shadow = "(null)"
 unix: group = "(null)"
 unix: radwtmp = "/usr/local/var/log/radius/radwtmp"
 unix: usegroup = no
 unix: cache_reload = 600
Module: Instantiated unix (unix)
Module: Loaded eap
 eap: default_eap_type = "md5"
 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 = 
"/usr/local/etc/raddb/certs/testCA/server_keycert.pem"
 tls: certificate_file = 
"/usr/local/etc/raddb/certs/testCA/server_keycert.pem"
 tls: CA_file = "/usr/local/etc/raddb/certs/testCA/cacert.pem"
 tls: private_key_password = ""
 tls: dh_file = "/usr/local/etc/raddb/certs/dh"
 tls: random_file = "/usr/local/etc/raddb/certs/random"
 tls: fragment_size = 1024
 tls: include_length = yes
 tls: check_crl = no
 tls: check_cert_cn = "(null)"
 tls: cipher_list = "(null)"
 tls: check_cert_issuer = "/C=GB/ST=Berkshire/L=Newbury/O=My Company Ltd"
rlm_eap_tls: Loading the certificate file as a chain
rlm_eap: Loaded and initialized type tls
 mschapv2: with_ntdomain_hack = no
rlm_eap: Loaded and initialized type mschapv2
Module: Instantiated eap (eap)
Module: Loaded preprocess
 preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups"
 preprocess: hints = "/usr/local/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
 preprocess: with_alvarion_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 = "/usr/local/etc/raddb/users"
 files: acctusersfile = "/usr/local/etc/raddb/acct_users"
 files: preproxy_usersfile = "/usr/local/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 = 
"/usr/local/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 = "/usr/local/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)
Initializing the thread pool...
 thread: start_servers = 5
 thread: max_servers = 32
 thread: min_spare_servers = 3
 thread: max_spare_servers = 10
 thread: max_requests_per_server = 0
 thread: cleanup_delay = 5
Thread spawned new child 1. Total threads in pool: 1
Thread spawned new child 2. Total threads in pool: 2
Thread spawned new child 3. Total threads in pool: 3
Thread spawned new child 4. Total threads in pool: 4
Thread spawned new child 5. Total threads in pool: 5
Thread pool initialized
Listening on authentication *:1812
Listening on accounting *:1813
Ready to process requests.
Thread 1 waiting to be assigned a request
Thread 2 waiting to be assigned a request
Thread 3 waiting to be assigned a request
Thread 4 waiting to be assigned a request
Thread 5 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.0.0.195:1812, id=121, length=99
--- Walking the entire request list ---
Waking up in 31 seconds...
Threads: total/active/spare threads = 5/0/5
Thread 1 got semaphore
Thread 1 handling request 0, (1 handled so far)
    User-Name = "testing.zssdk.edu.sk"
    NAS-IP-Address = 10.0.0.195
    NAS-Port-Type = Wireless-802.11
    EAP-Message = 0x02bf00190174657374696e672e7a7373646b2e6564752e736b
    Message-Authenticator = 0xef6f9f8a1914826c9e2d1b96313d9ba1
  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 = "testing.zssdk.edu.sk", 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 191 length 25
  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 DEFAULT at line 62
  modcall[authorize]: module "files" returns ok for request 0
modcall: leaving 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 md5
rlm_eap_md5: Issuing Challenge
  modcall[authenticate]: module "eap" returns handled for request 0
modcall: leaving group authenticate (returns handled) for request 0
Sending Access-Challenge of id 121 to 10.0.0.195 port 1812
    Reply-Message = "ALL OK"
    EAP-Message = 0x01c000160410b00adae82f7f2b29ad57a58d5565ae91
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x51818fc8c3ad564ec1951724db30b737
Finished request 0
Going to the next request

and here are many messages like this and it ends with:

Finished request 17
Going to the next request
Thread 3 waiting to be assigned a request
--- Walking the entire request list ---
Cleaning up request 4 ID 125 with timestamp 461696c4
Cleaning up request 5 ID 126 with timestamp 461696c4
Cleaning up request 6 ID 127 with timestamp 461696c4
Cleaning up request 7 ID 128 with timestamp 461696c4
Sending Access-Reject of id 132 to 10.0.0.195 port 1812
    Reply-Message = "ALL OK"
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 8 ID 129 with timestamp 461696c5
Cleaning up request 9 ID 130 with timestamp 461696c5
Cleaning up request 10 ID 131 with timestamp 461696c5
Cleaning up request 11 ID 132 with timestamp 461696c5
Cleaning up request 12 ID 133 with timestamp 461696c5
Cleaning up request 13 ID 134 with timestamp 461696c5
Cleaning up request 14 ID 135 with timestamp 461696c5
Cleaning up request 15 ID 136 with timestamp 461696c5
Cleaning up request 16 ID 137 with timestamp 461696c5
Cleaning up request 17 ID 138 with timestamp 461696c5
Nothing to do.  Sleeping until we see a request.

thanks for your help