Freeradius EAP-TLS - every 2nd (even) attempt unsuccessfull

[gracian at centrum.cz]

Hello all,
 
First, our environment configuration is:
FreeRADIUS Version 3.0.4, for host x86_64-redhat-linux-gnu configured for EAP-TLS
Cisco WLC 2504
Windows 7/8.1 clients
 
Problem: every 1st (odd) connection to WiFi network is without any problem and part of client's certificate contain "TLS-Client-Cert-Common-Name := 'mib at example.com'", which I check using check-eap-tls via part below, is visible:
server check-eap-tls {
 
authorize {
 
        update config {
                Auth-Type := Accept
        }
 
         if ("%{TLS-Client-Cert-Common-Name}" =~ /^[A-z.]*@example\.ccom$/) {
                update config {
                        Auth-Type := Accept
                }
        }
        else {
                update config {
                        Auth-Type := Reject
                }
                update reply {
                        Reply-Message := "Your certificate is not valid."
                }
        }
...
...
...
 
When I try to disconnect from wifi and connect again with the same client, connection fails. I noticed that debug output differ for successfull and unsuccessfull attempt in part below.
 
---------------------------------------------------------------
Successfull attempt log
---------------------------------------------------------------
(1) Found Auth-Type = EAP
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1)   authenticate {
(1)  eap : Expiring EAP session with state 0x3190079e31930a29
(1)  eap : Finished EAP session with state 0x3190079e31930a29
(1)  eap : Previous EAP request found for state 0x3190079e31930a29, released from the list
(1)  eap : Peer sent method TLS (13)
(1)  eap : EAP TLS (13)
(1)  eap : Calling eap_tls to process EAP data
(1)  eap_tls : Authenticate
(1)  eap_tls : processing EAP-TLS
  TLS Length 129
(1)  eap_tls : Length Included
(1)  eap_tls : eaptls_verify returned 11
(1)  eap_tls : (other): before/accept initialization
(1)  eap_tls : TLS_accept: before/accept initialization
(1)  eap_tls : <<< TLS 1.0 Handshake [length 007c], ClientHello
  SSL: Client requested cached session b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e
reading pairlist file /var/log/radius/tlscache/b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e.vps
Couldn't open /var/log/radius/tlscache/b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e.vps for reading: No such file or directory
  SSL: could not load persisted VPs for session b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e
(1)  eap_tls : TLS_accept: SSLv3 read client hello A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 0059], ServerHello
(1)  eap_tls : TLS_accept: SSLv3 write server hello A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 0909], Certificate
(1)  eap_tls : TLS_accept: SSLv3 write certificate A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
(1)  eap_tls : TLS_accept: SSLv3 write key exchange A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 00b2], CertificateRequest
(1)  eap_tls : TLS_accept: SSLv3 write certificate request A
(1)  eap_tls : TLS_accept: SSLv3 flush data
(1)  eap_tls : TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
 
 
------------------------------------------------
Unsuccessfull attempt log
------------------------------------------------
(1) Found Auth-Type = EAP
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1)   authenticate {
(1)  eap : Expiring EAP session with state 0x55a42e6f55a72377
(1)  eap : Finished EAP session with state 0x55a42e6f55a72377
(1)  eap : Previous EAP request found for state 0x55a42e6f55a72377, released from the list
(1)  eap : Peer sent method TLS (13)
(1)  eap : EAP TLS (13)
(1)  eap : Calling eap_tls to process EAP data
(1)  eap_tls : Authenticate
(1)  eap_tls : processing EAP-TLS
  TLS Length 129
(1)  eap_tls : Length Included
(1)  eap_tls : eaptls_verify returned 11
(1)  eap_tls : (other): before/accept initialization
(1)  eap_tls : TLS_accept: before/accept initialization
(1)  eap_tls : <<< TLS 1.0 Handshake [length 007c], ClientHello
  SSL: Client requested cached session b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e
reading pairlist file /var/log/radius/tlscache/b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e.vps
  SSL: Successfully restored session b76a6cf7f480f98fd8814048c4d959e55dd67c0e180edb92d885511c89beb44e
 
(1)  eap_tls : TLS_accept: SSLv3 read client hello A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 0051], ServerHello
(1)  eap_tls : TLS_accept: SSLv3 write server hello A
(1)  eap_tls : >>> TLS 1.0 ChangeCipherSpec [length 0001]
(1)  eap_tls : TLS_accept: SSLv3 write change cipher spec A
(1)  eap_tls : >>> TLS 1.0 Handshake [length 0010], Finished
(1)  eap_tls : TLS_accept: SSLv3 write finished A
 
 
(1)  eap_tls : TLS_accept: SSLv3 flush data
(1)  eap_tls : TLS_accept: Need to read more data: SSLv3 read finished A
In SSL Handshake Phase
In SSL Accept mode
 
 
 
I have noticed that during unsuccessfull attempt is in the log this part
(2)  eap : EAP TLS (13)
(2)  eap : Calling eap_tls to process EAP data
(2)  eap_tls : Authenticate
(2)  eap_tls : processing EAP-TLS
  TLS Length 59
(2)  eap_tls : Length Included
 
and this in successfull log:
(2)  eap : EAP TLS (13)
(2)  eap : Calling eap_tls to process EAP data
(2)  eap_tls : Authenticate
(2)  eap_tls : processing EAP-TLS
 
(2)  eap_tls : Received TLS ACK
(2)  eap_tls : Received TLS ACK
(2)  eap_tls : ACK handshake fragment handler
(2)  eap_tls : eaptls_verify returned 1
(2)  eap_tls : eaptls_process returned 13
(2)  eap : New EAP session, adding 'State' attribute to reply 0x3190079e33950a29
(2)   [eap] = handled
 
 
 
Sorry, but I'm new in Freeradius environment and I surely overlook something easy to solve, but in this moment I would kindly ask you, community for a help. 
 
It looks to me like a problem with skip some certificate check or caching, but  maybe I'm completely wrong.
 
 
Thank you for you help
Gracian