EAP-TLS Machine Auth difficulties

I'm attempting to use FreeRadius (I've tried 1.1.3 and 1.1.7) to
perform EAP-TLS authentication of Windows XP clients using Computer
certificates (machine authentication).

I've been following the guide at http://wiki.freeradius.org/WPA_HOWTO...ure_FreeRadius
for setting up FreeRadius. I generated my certificates with OpenSSL
and I have the TLS Client and TLS Server enhanced usage options
enabled. It seems like my authentication attempts cyclically repeat
forever. The Windows XP RAS Tracing files don't show anything
obviously wrong to me and comparing my FreeRadius log files with the
ones in http://www.freeradius.org/doc/EAPTLS.pdf it looks like I'm
following along pretty close until I just don't send the Access-
Accept.

If anyone could point me in the right direction to continue debugging
this I would be most obliged.

Thank You

FreeRadius Debug log (I trimmed the EAP fields as this is huge enough
as it is. I can put them up if need be.)
----------------------------------------
Starting - reading configuration files ...
reread_config: reading radiusd.conf
Config: including file: /etc/raddb/proxy.conf
Config: including file: /etc/raddb/clients.conf
Config: including file: /etc/raddb/snmp.conf
Config: including file: /etc/raddb/eap.conf
main: prefix = "/usr"
main: localstatedir = "/var"
main: logdir = "/var/log/radius"
main: libdir = "/usr/lib"
main: radacctdir = "/var/log/radius/radacct"
main: hostname_lookups = no
main: snmp = 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 = no
main: log_file = "/var/log/radius/radius.log"
main: log_auth = no
main: log_auth_badpass = no
main: log_auth_goodpass = no
main: pidfile = "/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 = "/usr/sbin/checkrad"
main: proxy_requests = no
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/lib
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded Counter
counter: filename = "/etc/raddb/db.daily"
counter: key = "User-Name"
counter: reset = "daily"
counter: count-attribute = "Acct-Session-Time"
counter: counter-name = "Daily-Session-Time"
counter: check-name = "Max-Daily-Session"
counter: allowed-servicetype = "Framed-User"
counter: cache-size = 5000
rlm_counter: Counter attribute Daily-Session-Time is number 1830
rlm_counter: Current Time: 1200141483 [2008-01-12 07:38:03], Next
reset 1200200400 [2008-01-13 00:00:00]
Module: Instantiated counter (daily)
Module: Loaded eap
eap: default_eap_type = "tls"
eap: timer_expire = 60
eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no
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 = "/etc/raddb/certs/radius-server.key"
tls: certificate_file = "/etc/raddb/certs/radius-server.crt"
tls: CA_file = "/etc/raddb/certs/ca.crt"
tls: private_key_password = "radius-server"
tls: dh_file = "/etc/raddb/certs/dh"
tls: random_file = "/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 = "(null)"
rlm_eap_tls: Loading the certificate file as a chain
rlm_eap: Loaded and initialized type tls
Module: Instantiated eap (eap)
Module: Loaded preprocess
preprocess: huntgroups = "/etc/raddb/huntgroups"
preprocess: hints = "/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 files
files: usersfile = "/etc/raddb/users"
files: acctusersfile = "/etc/raddb/acct_users"
files: preproxy_usersfile = "/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/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/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.1.1:1645, id=248,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x2410f2596560e6f9af62b1d78292f498
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 544
NAS-Port-Id = "544"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "preprocess" returns ok for request 0
rlm_eap: EAP packet type response id 2 length 41
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 host/laptop.test.net at line 216
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 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: leaving group authenticate (returns handled) for request 0
Sending Access-Challenge of id 248 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x20aab1dc896a7dd4772e9472c620babc
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.1.1:1645, id=249,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x5af399ba40e3e07b5da8b1d763be27c1
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 544
NAS-Port-Id = "544"
State = 0x20aab1dc896a7dd4772e9472c620babc
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "preprocess" returns ok for request 1
rlm_eap: EAP packet type response id 3 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 host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 1
modcall: leaving 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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 1
modcall: leaving group authenticate (returns handled) for request 1
Sending Access-Challenge of id 249 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xefdaf4489ce48e3693838e262b731396
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=250,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x51e6c839b18a997b4b15b2230973bfee
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 544
NAS-Port-Id = "544"
State = 0xefdaf4489ce48e3693838e262b731396
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
modcall[authorize]: module "preprocess" returns ok for request 2
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 2
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 2
modcall: leaving 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: leaving group authenticate (returns handled) for request 2
Sending Access-Challenge of id 250 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x8ba3b6c719db5e67f047296275ae97f0
Finished request 2
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=251,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x75b49ceae49189e4d3af46e00293189e
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 544
NAS-Port-Id = "544"
State = 0x8ba3b6c719db5e67f047296275ae97f0
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
modcall[authorize]: module "preprocess" returns ok for request 3
rlm_eap: EAP packet type response id 5 length 253
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 host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 3
modcall: leaving 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: Length Included
eaptls_verify returned 11
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 3
modcall: leaving group authenticate (returns handled) for request 3
Sending Access-Challenge of id 251 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x8def94d978d4a4b5edf95e7b7ec25f42
Finished request 3
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 248 with timestamp 4788b4b4
Cleaning up request 1 ID 249 with timestamp 4788b4b4
Cleaning up request 2 ID 250 with timestamp 4788b4b4
Cleaning up request 3 ID 251 with timestamp 4788b4b4
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=252,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x7e993724c9ad6c715ad83794ae5c2386
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 545
NAS-Port-Id = "545"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
modcall[authorize]: module "preprocess" returns ok for request 4
rlm_eap: EAP packet type response id 3 length 41
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 4
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 4
modcall: leaving group authorize (returns updated) for request 4
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 4
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 4
modcall: leaving group authenticate (returns handled) for request 4
Sending Access-Challenge of id 252 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xc1457931b3fd695a5545655f1426ec08
Finished request 4
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=253,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x5295f07c19caccf1b0c32524da131911
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 545
NAS-Port-Id = "545"
State = 0xc1457931b3fd695a5545655f1426ec08
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
modcall[authorize]: module "preprocess" returns ok for request 5
rlm_eap: EAP packet type response id 4 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 5
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 5
modcall: leaving group authorize (returns updated) for request 5
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 5
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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 5
modcall: leaving group authenticate (returns handled) for request 5
Sending Access-Challenge of id 253 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x18400dcd910e29a125993eebe8c39717
Finished request 5
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=254,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x8f0a3600c50fb7b82a52f3e24257f9b6
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 545
NAS-Port-Id = "545"
State = 0x18400dcd910e29a125993eebe8c39717
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 6
modcall[authorize]: module "preprocess" returns ok for request 6
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 6
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 6
modcall: leaving group authorize (returns updated) for request 6
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 6
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 6
modcall: leaving group authenticate (returns handled) for request 6
Sending Access-Challenge of id 254 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x834c335c5371e1ef258cc0e6a3d95521
Finished request 6
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=255,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x499d647b881338d663f2386e9013976d
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 545
NAS-Port-Id = "545"
State = 0x834c335c5371e1ef258cc0e6a3d95521
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
modcall[authorize]: module "preprocess" returns ok for request 7
rlm_eap: EAP packet type response id 6 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 7
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 7
modcall: leaving group authorize (returns updated) for request 7
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
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
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 7
modcall: leaving group authenticate (returns handled) for request 7
Sending Access-Challenge of id 255 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb405a3bb495297f12336f506911a5179
Finished request 7
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 4 ID 252 with timestamp 4788b4c8
Cleaning up request 5 ID 253 with timestamp 4788b4c8
Cleaning up request 6 ID 254 with timestamp 4788b4c8
Cleaning up request 7 ID 255 with timestamp 4788b4c8
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=0,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x2cff03c84894161bdbf601015b15d86d
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 8
modcall[authorize]: module "preprocess" returns ok for request 8
rlm_eap: EAP packet type response id 3 length 41
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 8
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 8
modcall: leaving group authorize (returns updated) for request 8
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 8
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 8
modcall: leaving group authenticate (returns handled) for request 8
Sending Access-Challenge of id 0 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xecb382f07dbb9f05c3261437c02305a6
Finished request 8
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=1,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0xe6875263299701da6eaa998632788f80
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0xecb382f07dbb9f05c3261437c02305a6
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 9
modcall[authorize]: module "preprocess" returns ok for request 9
rlm_eap: EAP packet type response id 4 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 9
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 9
modcall: leaving group authorize (returns updated) for request 9
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 9
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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 9
modcall: leaving group authenticate (returns handled) for request 9
Sending Access-Challenge of id 1 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x852351b66d13aa394d5d8595a96f7191
Finished request 9
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=2,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0xd688ab18397a365c67c4d83b037e42de
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0x852351b66d13aa394d5d8595a96f7191
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 10
modcall[authorize]: module "preprocess" returns ok for request 10
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 10
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 10
modcall: leaving group authorize (returns updated) for request 10
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 10
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 10
modcall: leaving group authenticate (returns handled) for request 10
Sending Access-Challenge of id 2 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf04c3cecc912570d381faaa56964641f
Finished request 10
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=3,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x47f733504ec4024df984e4aab0e4bd76
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0xf04c3cecc912570d381faaa56964641f
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 11
modcall[authorize]: module "preprocess" returns ok for request 11
rlm_eap: EAP packet type response id 6 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 11
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 11
modcall: leaving group authorize (returns updated) for request 11
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 11
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
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 11
modcall: leaving group authenticate (returns handled) for request 11
Sending Access-Challenge of id 3 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x5a1a3f9e7061ee2ff3c37d35ada05564
Finished request 11
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 8 ID 0 with timestamp 4788b4da
Cleaning up request 9 ID 1 with timestamp 4788b4da
Cleaning up request 10 ID 2 with timestamp 4788b4da
Cleaning up request 11 ID 3 with timestamp 4788b4da
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=4,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x82ff022116da00c3753c60870ba4e320
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 12
modcall[authorize]: module "preprocess" returns ok for request 12
rlm_eap: EAP packet type response id 8 length 41
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 12
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 12
modcall: leaving group authorize (returns updated) for request 12
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 12
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 12
modcall: leaving group authenticate (returns handled) for request 12
Sending Access-Challenge of id 4 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xfb6aaa806a3819654b0674593177a4db
Finished request 12
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=5,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x5e9dce9729811e3cc9054cb9a1bc4250
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0xfb6aaa806a3819654b0674593177a4db
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 13
modcall[authorize]: module "preprocess" returns ok for request 13
rlm_eap: EAP packet type response id 9 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 13
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 13
modcall: leaving group authorize (returns updated) for request 13
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 13
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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 13
modcall: leaving group authenticate (returns handled) for request 13
Sending Access-Challenge of id 5 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x9d97ab19691baf93530f8cfbc346b5e9
Finished request 13
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=6,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x561655f7f03d89651e6ba905d73d0c63
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0x9d97ab19691baf93530f8cfbc346b5e9
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 14
modcall[authorize]: module "preprocess" returns ok for request 14
rlm_eap: EAP packet type response id 10 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 14
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 14
modcall: leaving group authorize (returns updated) for request 14
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 14
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 14
modcall: leaving group authenticate (returns handled) for request 14
Sending Access-Challenge of id 6 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x426ff8ce0e6efaac5a91789b32a1e495
Finished request 14
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=7,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x6bcca414495618f1d1065ce2f7878080
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 546
NAS-Port-Id = "546"
State = 0x426ff8ce0e6efaac5a91789b32a1e495
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 15
modcall[authorize]: module "preprocess" returns ok for request 15
rlm_eap: EAP packet type response id 11 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 15
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 15
modcall: leaving group authorize (returns updated) for request 15
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 15
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
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 15
modcall: leaving group authenticate (returns handled) for request 15
Sending Access-Challenge of id 7 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x294fd55b0f1734eb7ddbc0742f18db56
Finished request 15
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 12 ID 4 with timestamp 4788b4ec
Cleaning up request 13 ID 5 with timestamp 4788b4ec
Cleaning up request 14 ID 6 with timestamp 4788b4ec
Cleaning up request 15 ID 7 with timestamp 4788b4ec
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=8,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x1dd1a0b369c63fcd6cb7822a9b024f37
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 547
NAS-Port-Id = "547"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 16
modcall[authorize]: module "preprocess" returns ok for request 16
rlm_eap: EAP packet type response id 3 length 41
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 16
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 16
modcall: leaving group authorize (returns updated) for request 16
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 16
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 16
modcall: leaving group authenticate (returns handled) for request 16
Sending Access-Challenge of id 8 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x308feba4b45400144cce6584be195029
Finished request 16
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=9,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x1059803b547fc68fb8deae1f9cc0ed98
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 547
NAS-Port-Id = "547"
State = 0x308feba4b45400144cce6584be195029
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 17
modcall[authorize]: module "preprocess" returns ok for request 17
rlm_eap: EAP packet type response id 4 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 17
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 17
modcall: leaving group authorize (returns updated) for request 17
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 17
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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 17
modcall: leaving group authenticate (returns handled) for request 17
Sending Access-Challenge of id 9 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6d198e86cf88483a912790677df80e51
Finished request 17
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=10,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x5b726e062369754dde50ad52532334c6
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 547
NAS-Port-Id = "547"
State = 0x6d198e86cf88483a912790677df80e51
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 18
modcall[authorize]: module "preprocess" returns ok for request 18
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 18
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 18
modcall: leaving group authorize (returns updated) for request 18
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 18
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 18
modcall: leaving group authenticate (returns handled) for request 18
Sending Access-Challenge of id 10 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x7a0e77333298cd6ce42c24064b8fffbf
Finished request 18
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=11,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0xde81ba853516440f99d56b3775edff07
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 547
NAS-Port-Id = "547"
State = 0x7a0e77333298cd6ce42c24064b8fffbf
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 19
modcall[authorize]: module "preprocess" returns ok for request 19
rlm_eap: EAP packet type response id 6 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 19
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 19
modcall: leaving group authorize (returns updated) for request 19
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 19
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
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 19
modcall: leaving group authenticate (returns handled) for request 19
Sending Access-Challenge of id 11 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x8ce22fbb78dfe224ba603cbae20eb4b1
Finished request 19
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 16 ID 8 with timestamp 4788b4ff
Cleaning up request 17 ID 9 with timestamp 4788b4ff
Cleaning up request 18 ID 10 with timestamp 4788b4ff
Cleaning up request 19 ID 11 with timestamp 4788b4ff
Nothing to do. Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=12,
length=196
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x2b91b1e9d07c6dd1e4558b554ae732dc
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 548
NAS-Port-Id = "548"
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 20
modcall[authorize]: module "preprocess" returns ok for request 20
rlm_eap: EAP packet type response id 3 length 41
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 20
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 20
modcall: leaving group authorize (returns updated) for request 20
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 20
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 20
modcall: leaving group authenticate (returns handled) for request 20
Sending Access-Challenge of id 12 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x1732306572fa8ab013037f428be90b16
Finished request 20
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=13,
length=253
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0xaee22dfb632ceeea4692f5b8292fdf7a
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 548
NAS-Port-Id = "548"
State = 0x1732306572fa8ab013037f428be90b16
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 21
modcall[authorize]: module "preprocess" returns ok for request 21
rlm_eap: EAP packet type response id 4 length 80
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 21
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 21
modcall: leaving group authorize (returns updated) for request 21
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 21
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 0662], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0089],
CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 21
modcall: leaving group authenticate (returns handled) for request 21
Sending Access-Challenge of id 13 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf5e7194c6de14e3b8bbb54fbe5f51c4a
Finished request 21
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=14,
length=179
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0xc33a17cf0d78c887b0ab2aed9ade5939
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 548
NAS-Port-Id = "548"
State = 0xf5e7194c6de14e3b8bbb54fbe5f51c4a
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 22
modcall[authorize]: module "preprocess" returns ok for request 22
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 22
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 22
modcall: leaving group authorize (returns updated) for request 22
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 22
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 22
modcall: leaving group authenticate (returns handled) for request 22
Sending Access-Challenge of id 14 to 192.168.1.1 port 1645
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x0bc94dd9f17ea08baac5abe9a4e4482b
Finished request 22
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.1:1645, id=15,
length=1234
User-Name = "host/laptop.test.net"
Framed-MTU = 1400
Called-Station-Id = "001c.0f83.09d0"
Calling-Station-Id = "0040.96a3.b9ab"
Service-Type = Login-User
Message-Authenticator = 0x210557d94651017de7e692fe355d5358
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
EAP-Message = ...
NAS-Port-Type = Wireless-802.11
NAS-Port = 548
NAS-Port-Id = "548"
State = 0x0bc94dd9f17ea08baac5abe9a4e4482b
NAS-IP-Address = 192.168.1.1
NAS-Identifier = "ap11"
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 23
modcall[authorize]: module "preprocess" returns ok for request 23
rlm_eap: EAP packet type response id 6 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 23
users: Matched entry host/laptop.test.net at line 216
modcall[authorize]: module "files" returns ok for request 23
modcall: leaving group authorize (returns updated) for request 23
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 23
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
rlm_eap_tls: <<< TLS 1.0 Handshake [length 02d7], Certificate
chain-depth=1,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = ca.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
chain-depth=0,
error=0
--> User-Name = host/laptop.test.net
--> BUF-Name = laptop.test.net
--> subject = /C=US/O=Test/OU=Lab/CN=laptop.test.net
--> issuer = /C=US/O=Test/OU=Lab/CN=ca.test.net
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086],
CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 23
modcall: leaving group authenticate (returns handled) for request 23
Sending Access-Challenge of id 15 to 192.168.1.1 port 1645
EAP-Message = ...
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x38c27417cc1dc85e2a4cbf8d9e98dc46
Finished request 23
Going to the next request
Waking up in 6 seconds...