Strange things with android phone

22 Aug 2015

      I have configured and working wifi with eap-tls authentication.
I want to use another root ca, so I did the following steps.

openssl genrsa -aes256 -out private/wifi,beta,ca.key 4096

openssl req -new -out cacerts/wifi,beta,ca.pem -subj "/C=PL/ST=Mazowieckie/L=Warszawa/O=beta/OU=wifi/CN=beta-wifi-ca/emailAddress=kjonca@poczta.onet.pl" -x509 -days 3650 -extensions v3_ca -key private/wifi,beta,ca.key

openssl req -new -out req.csr -subj "/C=PL/ST=Mazowieckie/O=beta/OU=beta.kjonca/CN=selen.kjonca" -key ../private/selen.kjonca.1.key #this is phone key

openssl ca -in req.csr -cert cacerts/wifi,beta,ca.pem -keyfile private/wifi,beta,ca.key -extensions xpclient_ext -extfile ../xp.ext -out certs/wifi,selen,1.pem

openssl x509 -x509toreq -in certs/wifi,beta-wifi-beta,2,1.pem -out req.csr -signkey private/wifi,beta-wifi-beta,2.key #this is key for freeradius instance

openssl ca -in req.csr -cert cacerts/wifi,beta,ca.pem -keyfile private/wifi,beta,ca.key -out certs/wifi,beta-wifi-beta,2.5.pem

openssl pkcs12 -export -certfile cacerts/wifi,beta,ca.pem -in certs/wifi,selen,1.pem -inkey ../private/selen.kjonca.1.key -out wifi,selen.p12

Then *.p12 file was sent to phone and imported into cert store.
And strange things happen:
When "CA cert" field in wifi network definition is set then phone can't
connect. When is empty - eweything works.

Here some logs.

12:02:28 2015 : Info: Cleaning up request 83 ID 240 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Cleaning up request 84 ID 241 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Cleaning up request 85 ID 242 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Cleaning up request 86 ID 243 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Cleaning up request 87 ID 244 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Cleaning up request 88 ID 245 with timestamp +1556
Sat Aug 22 12:02:28 2015 : Info: Ready to process requests.
Sat Aug 22 12:04:43 2015 : Debug: Thread 5 got semaphore
Sat Aug 22 12:04:43 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:43 2015 : Debug: Thread 5 handling request 89, (18 handled so far)
Sat Aug 22 12:04:43 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authorize {
Sat Aug 22 12:04:43 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:43 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:43 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:43 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP packet type response id 154 length 17
Sat Aug 22 12:04:43 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:43 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:43 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:43 2015 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Sat Aug 22 12:04:43 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:43 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:43 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:43 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authenticate {
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP Identity
Sat Aug 22 12:04:43 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:43 2015 : Info: [tls] Requiring client certificate
Sat Aug 22 12:04:43 2015 : Info: [tls] Initiate
Sat Aug 22 12:04:43 2015 : Info: [tls] Start returned 1
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = handled
Sat Aug 22 12:04:43 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:04:43 2015 : Info: Finished request 89.
Sat Aug 22 12:04:43 2015 : Debug: Going to the next request
Sat Aug 22 12:04:43 2015 : Debug: Thread 5 waiting to be assigned a request
Sat Aug 22 12:04:43 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:43 2015 : Debug: Thread 3 got semaphore
Sat Aug 22 12:04:43 2015 : Debug: Thread 3 handling request 90, (19 handled so far)
Sat Aug 22 12:04:43 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authorize {
Sat Aug 22 12:04:43 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:43 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:43 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:43 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP packet type response id 155 length 204
Sat Aug 22 12:04:43 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:43 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:43 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:43 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:43 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:43 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authenticate {
Sat Aug 22 12:04:43 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:04:43 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:43 2015 : Info: [tls] Authenticate
Sat Aug 22 12:04:43 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:04:43 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:04:43 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:04:43 2015 : Info: [tls]     (other): before/accept initialization
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: before/accept initialization
Sat Aug 22 12:04:43 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:43 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 00c1], ClientHello  
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0039], ServerHello  
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0695], Certificate  
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 00cb], ServerKeyExchange  
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:43 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 000e], CertificateRequest  
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:43 2015 : Info: [tls]     TLS_accept: Need to read more data: unknown state
Sat Aug 22 12:04:43 2015 : Debug: In SSL Handshake Phase 
Sat Aug 22 12:04:43 2015 : Debug: In SSL Accept mode  
Sat Aug 22 12:04:43 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = handled
Sat Aug 22 12:04:43 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:04:43 2015 : Info: Finished request 90.
Sat Aug 22 12:04:43 2015 : Debug: Going to the next request
Sat Aug 22 12:04:43 2015 : Debug: Thread 3 waiting to be assigned a request
Sat Aug 22 12:04:43 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:43 2015 : Debug: Thread 4 got semaphore
Sat Aug 22 12:04:43 2015 : Debug: Thread 4 handling request 91, (19 handled so far)
Sat Aug 22 12:04:43 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authorize {
Sat Aug 22 12:04:43 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:43 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:43 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:43 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP packet type response id 156 length 6
Sat Aug 22 12:04:43 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:43 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:43 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:43 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:43 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:43 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:43 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:43 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:43 2015 : Info: +group authenticate {
Sat Aug 22 12:04:43 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:04:43 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:04:43 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:43 2015 : Info: [tls] Authenticate
Sat Aug 22 12:04:43 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:04:43 2015 : Info: [tls] Received TLS ACK
Sat Aug 22 12:04:43 2015 : Info: [tls] ACK handshake fragment handler
Sat Aug 22 12:04:43 2015 : Info: [tls] eaptls_verify returned 1 
Sat Aug 22 12:04:43 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:04:43 2015 : Info: ++[eap] = handled
Sat Aug 22 12:04:43 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:04:43 2015 : Info: Finished request 91.
Sat Aug 22 12:04:43 2015 : Debug: Going to the next request
Sat Aug 22 12:04:43 2015 : Debug: Thread 4 waiting to be assigned a request
Sat Aug 22 12:04:44 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:44 2015 : Debug: Thread 1 got semaphore
Sat Aug 22 12:04:44 2015 : Debug: Thread 1 handling request 92, (19 handled so far)
Sat Aug 22 12:04:44 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authorize {
Sat Aug 22 12:04:44 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:44 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:44 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:44 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP packet type response id 157 length 253
Sat Aug 22 12:04:44 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:44 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:44 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:44 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:44 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:44 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authenticate {
Sat Aug 22 12:04:44 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:04:44 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:44 2015 : Info: [tls] Authenticate
Sat Aug 22 12:04:44 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:04:44 2015 : Debug:   TLS Length 1577
Sat Aug 22 12:04:44 2015 : Info: [tls] Received EAP-TLS First Fragment of the message
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_verify returned 9 
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = handled
Sat Aug 22 12:04:44 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:04:44 2015 : Info: Finished request 92.
Sat Aug 22 12:04:44 2015 : Debug: Going to the next request
Sat Aug 22 12:04:44 2015 : Debug: Thread 1 waiting to be assigned a request
Sat Aug 22 12:04:44 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:44 2015 : Debug: Thread 2 got semaphore
Sat Aug 22 12:04:44 2015 : Debug: Thread 2 handling request 93, (19 handled so far)
Sat Aug 22 12:04:44 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authorize {
Sat Aug 22 12:04:44 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:44 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:44 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:44 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP packet type response id 158 length 185
Sat Aug 22 12:04:44 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:44 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:44 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:44 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:44 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:44 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authenticate {
Sat Aug 22 12:04:44 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:04:44 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:44 2015 : Info: [tls] Authenticate
Sat Aug 22 12:04:44 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:04:44 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0493], Certificate  
Sat Aug 22 12:04:44 2015 : Info: [tls] chain-depth=1, 
Sat Aug 22 12:04:44 2015 : Info: [tls] error=0
Sat Aug 22 12:04:44 2015 : Info: [tls] --> User-Name = selen.kjonca
Sat Aug 22 12:04:44 2015 : Info: [tls] --> BUF-Name = beta-wifi-ca-2
Sat Aug 22 12:04:44 2015 : Info: [tls] --> subject = /C=PL/ST=Mazowieckie/L=Warszawa/O=beta/OU=wifi/CN=beta-wifi-ca-2/emailAddress=kjonca@poczta.onet.pl
Sat Aug 22 12:04:44 2015 : Info: [tls] --> issuer  = /C=PL/ST=Mazowieckie/L=Warszawa/O=beta/OU=wifi/CN=beta-wifi-ca-2/emailAddress=kjonca@poczta.onet.pl
Sat Aug 22 12:04:44 2015 : Info: [tls] --> verify return:1
Sat Aug 22 12:04:44 2015 : Info: [tls] 	expand: %{User-Name} -> selen.kjonca
Sat Aug 22 12:04:44 2015 : Info: [tls] checking certificate CN (selen.kjonca) with xlat'ed value (selen.kjonca)
Sat Aug 22 12:04:44 2015 : Info: [tls] chain-depth=0, 
Sat Aug 22 12:04:44 2015 : Info: [tls] error=0
Sat Aug 22 12:04:44 2015 : Info: [tls] --> User-Name = selen.kjonca
Sat Aug 22 12:04:44 2015 : Info: [tls] --> BUF-Name = selen.kjonca
Sat Aug 22 12:04:44 2015 : Info: [tls] --> subject = /C=PL/ST=Mazowieckie/O=beta/OU=beta.kjonca/CN=selen.kjonca
Sat Aug 22 12:04:44 2015 : Info: [tls] --> issuer  = /C=PL/ST=Mazowieckie/L=Warszawa/O=beta/OU=wifi/CN=beta-wifi-ca-2/emailAddress=kjonca@poczta.onet.pl
Sat Aug 22 12:04:44 2015 : Info: [tls] --> verify return:1
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange  
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0106], CertificateVerify  
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 0010], Finished  
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:04:44 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0010], Finished  
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:04:44 2015 : Info: [tls]     (other): SSL negotiation finished successfully
Sat Aug 22 12:04:44 2015 : Debug: SSL Connection Established 
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = handled
Sat Aug 22 12:04:44 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:04:44 2015 : Info: Finished request 93.
Sat Aug 22 12:04:44 2015 : Debug: Going to the next request
Sat Aug 22 12:04:44 2015 : Debug: Thread 2 waiting to be assigned a request
Sat Aug 22 12:04:44 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:04:44 2015 : Debug: Thread 5 got semaphore
Sat Aug 22 12:04:44 2015 : Debug: Thread 5 handling request 94, (19 handled so far)
Sat Aug 22 12:04:44 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authorize {
Sat Aug 22 12:04:44 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[chap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[digest] = noop
Sat Aug 22 12:04:44 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:04:44 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:04:44 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP packet type response id 159 length 6
Sat Aug 22 12:04:44 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = updated
Sat Aug 22 12:04:44 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:04:44 2015 : Info: ++[files] = ok
Sat Aug 22 12:04:44 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:04:44 2015 : Info: ++[pap] = noop
Sat Aug 22 12:04:44 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:04:44 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:04:44 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group authenticate {
Sat Aug 22 12:04:44 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:04:44 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:04:44 2015 : Info: [eap] processing type tls
Sat Aug 22 12:04:44 2015 : Info: [tls] Authenticate
Sat Aug 22 12:04:44 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:04:44 2015 : Info: [tls] Received TLS ACK
Sat Aug 22 12:04:44 2015 : Info: [tls] ACK handshake is finished
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_verify returned 3 
Sat Aug 22 12:04:44 2015 : Info: [tls] eaptls_process returned 3 
Sat Aug 22 12:04:44 2015 : Info: [tls] Adding user data to cached session
Sat Aug 22 12:04:44 2015 : Info: [eap] Freeing handler
Sat Aug 22 12:04:44 2015 : Info: ++[eap] = ok
Sat Aug 22 12:04:44 2015 : Info: +} # group authenticate = ok
Sat Aug 22 12:04:44 2015 : Auth: Login OK: [selen.kjonca] (from client ni port 2 cli 00-08-22-4F-62-54)
Sat Aug 22 12:04:44 2015 : Info: # Executing section post-auth from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:04:44 2015 : Info: +group post-auth {
Sat Aug 22 12:04:44 2015 : Info: ++[exec] = noop
Sat Aug 22 12:04:44 2015 : Info: +} # group post-auth = noop
Sat Aug 22 12:04:44 2015 : Info: Finished request 94.
Sat Aug 22 12:04:44 2015 : Debug: Going to the next request
Sat Aug 22 12:04:44 2015 : Debug: Thread 5 waiting to be assigned a request
Sat Aug 22 12:04:45 2015 : Debug: Waking up in 3.9 seconds.
Sat Aug 22 12:04:48 2015 : Info: Cleaning up request 89 ID 246 with timestamp +1696
Sat Aug 22 12:04:48 2015 : Info: Cleaning up request 90 ID 247 with timestamp +1696
Sat Aug 22 12:04:48 2015 : Info: Cleaning up request 91 ID 248 with timestamp +1696
Sat Aug 22 12:04:49 2015 : Info: Cleaning up request 92 ID 249 with timestamp +1697
Sat Aug 22 12:04:49 2015 : Info: Cleaning up request 93 ID 250 with timestamp +1697
Sat Aug 22 12:04:49 2015 : Info: Cleaning up request 94 ID 251 with timestamp +1697
Sat Aug 22 12:04:49 2015 : Info: Ready to process requests.
Sat Aug 22 12:05:05 2015 : Debug: Thread 3 got semaphore
Sat Aug 22 12:05:05 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:05 2015 : Debug: Thread 3 handling request 95, (20 handled so far)
Sat Aug 22 12:05:05 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authorize {
Sat Aug 22 12:05:05 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:05 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:05 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:05 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP packet type response id 60 length 17
Sat Aug 22 12:05:05 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:05 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:05 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:05 2015 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Sat Aug 22 12:05:05 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:05 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:05 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:05 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authenticate {
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP Identity
Sat Aug 22 12:05:05 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:05 2015 : Info: [tls] Requiring client certificate
Sat Aug 22 12:05:05 2015 : Info: [tls] Initiate
Sat Aug 22 12:05:05 2015 : Info: [tls] Start returned 1
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:05 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:05 2015 : Info: Finished request 95.
Sat Aug 22 12:05:05 2015 : Debug: Going to the next request
Sat Aug 22 12:05:05 2015 : Debug: Thread 3 waiting to be assigned a request
Sat Aug 22 12:05:05 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:05 2015 : Debug: Thread 4 got semaphore
Sat Aug 22 12:05:05 2015 : Debug: Thread 4 handling request 96, (20 handled so far)
Sat Aug 22 12:05:05 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authorize {
Sat Aug 22 12:05:05 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:05 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:05 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:05 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP packet type response id 61 length 204
Sat Aug 22 12:05:05 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:05 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:05 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:05 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:05 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:05 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authenticate {
Sat Aug 22 12:05:05 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:05 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:05 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:05 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:05:05 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:05:05 2015 : Info: [tls]     (other): before/accept initialization
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: before/accept initialization
Sat Aug 22 12:05:05 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 00c1], ClientHello  
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0039], ServerHello  
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0695], Certificate  
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 00cb], ServerKeyExchange  
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 000e], CertificateRequest  
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:05 2015 : Info: [tls]     TLS_accept: Need to read more data: unknown state
Sat Aug 22 12:05:05 2015 : Debug: In SSL Handshake Phase 
Sat Aug 22 12:05:05 2015 : Debug: In SSL Accept mode  
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:05 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:05 2015 : Info: Finished request 96.
Sat Aug 22 12:05:05 2015 : Debug: Going to the next request
Sat Aug 22 12:05:05 2015 : Debug: Thread 4 waiting to be assigned a request
Sat Aug 22 12:05:05 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:05 2015 : Debug: Thread 1 got semaphore
Sat Aug 22 12:05:05 2015 : Debug: Thread 1 handling request 97, (20 handled so far)
Sat Aug 22 12:05:05 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authorize {
Sat Aug 22 12:05:05 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:05 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:05 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:05 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP packet type response id 62 length 6
Sat Aug 22 12:05:05 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:05 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:05 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:05 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:05 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:05 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authenticate {
Sat Aug 22 12:05:05 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:05 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:05 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:05 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:05 2015 : Info: [tls] Received TLS ACK
Sat Aug 22 12:05:05 2015 : Info: [tls] ACK handshake fragment handler
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_verify returned 1 
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:05 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:05 2015 : Info: Finished request 97.
Sat Aug 22 12:05:05 2015 : Debug: Going to the next request
Sat Aug 22 12:05:05 2015 : Debug: Thread 1 waiting to be assigned a request
Sat Aug 22 12:05:05 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:05 2015 : Debug: Thread 2 got semaphore
Sat Aug 22 12:05:05 2015 : Debug: Thread 2 handling request 98, (20 handled so far)
Sat Aug 22 12:05:05 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authorize {
Sat Aug 22 12:05:05 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:05 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:05 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:05 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP packet type response id 63 length 13
Sat Aug 22 12:05:05 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:05 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:05 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:05 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:05 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:05 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:05 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:05 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group authenticate {
Sat Aug 22 12:05:05 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:05 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:05 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:05 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:05 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:05:05 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:05:05 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:05:05 2015 : Info: [tls] <<< TLS 1.0 Alert [length 0002], fatal unknown_ca  
Sat Aug 22 12:05:05 2015 : Error: TLS Alert read:fatal:unknown CA
Sat Aug 22 12:05:05 2015 : Error:     TLS_accept: failed in unknown state
Sat Aug 22 12:05:05 2015 : Error: rlm_eap: SSL error error:14094418:SSL routines:ssl3_read_bytes:tlsv1 alert unknown ca
Sat Aug 22 12:05:05 2015 : Error: SSL: SSL_read failed inside of TLS (-1), TLS session fails.
Sat Aug 22 12:05:05 2015 : Debug: TLS receive handshake failed during operation
Sat Aug 22 12:05:05 2015 : Info: [tls] eaptls_process returned 4 
Sat Aug 22 12:05:05 2015 : Info: [eap] Handler failed in EAP/tls
Sat Aug 22 12:05:05 2015 : Info: [eap] Failed in EAP select
Sat Aug 22 12:05:05 2015 : Info: ++[eap] = invalid
Sat Aug 22 12:05:05 2015 : Info: +} # group authenticate = invalid
Sat Aug 22 12:05:05 2015 : Info: Failed to authenticate the user.
Sat Aug 22 12:05:05 2015 : Auth: Login incorrect (TLS Alert read:fatal:unknown CA): [selen.kjonca] (from client ni port 2 cli 00-08-22-4F-62-54)
Sat Aug 22 12:05:05 2015 : Info: Using Post-Auth-Type REJECT
Sat Aug 22 12:05:05 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:05 2015 : Info: +group REJECT {
Sat Aug 22 12:05:05 2015 : Info: [attr_filter.access_reject] 	expand: %{User-Name} -> selen.kjonca
Sat Aug 22 12:05:05 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Sat Aug 22 12:05:05 2015 : Info: ++[attr_filter.access_reject] = updated
Sat Aug 22 12:05:05 2015 : Info: +} # group REJECT = updated
Sat Aug 22 12:05:05 2015 : Info: Delaying reject of request 98 for 1 seconds
Sat Aug 22 12:05:05 2015 : Debug: Going to the next request
Sat Aug 22 12:05:05 2015 : Debug: Thread 2 waiting to be assigned a request
Sat Aug 22 12:05:06 2015 : Info: Sending delayed reject for request 98
Sat Aug 22 12:05:06 2015 : Debug: Waking up in 3.9 seconds.
Sat Aug 22 12:05:07 2015 : Debug: Thread 5 got semaphore
Sat Aug 22 12:05:07 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:07 2015 : Debug: Thread 5 handling request 99, (20 handled so far)
Sat Aug 22 12:05:07 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authorize {
Sat Aug 22 12:05:07 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:07 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:07 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:07 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP packet type response id 162 length 17
Sat Aug 22 12:05:07 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:07 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:07 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:07 2015 : Info: [pap] WARNING! No "known good" password found for the user.  Authentication may fail because of this.
Sat Aug 22 12:05:07 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:07 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:07 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:07 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authenticate {
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP Identity
Sat Aug 22 12:05:07 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:07 2015 : Info: [tls] Requiring client certificate
Sat Aug 22 12:05:07 2015 : Info: [tls] Initiate
Sat Aug 22 12:05:07 2015 : Info: [tls] Start returned 1
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:07 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:07 2015 : Info: Finished request 99.
Sat Aug 22 12:05:07 2015 : Debug: Going to the next request
Sat Aug 22 12:05:07 2015 : Debug: Thread 5 waiting to be assigned a request
Sat Aug 22 12:05:07 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:07 2015 : Debug: Thread 3 got semaphore
Sat Aug 22 12:05:07 2015 : Debug: Thread 3 handling request 100, (21 handled so far)
Sat Aug 22 12:05:07 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authorize {
Sat Aug 22 12:05:07 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:07 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:07 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:07 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP packet type response id 163 length 204
Sat Aug 22 12:05:07 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:07 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:07 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:07 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:07 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:07 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authenticate {
Sat Aug 22 12:05:07 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:07 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:07 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:07 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:05:07 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:05:07 2015 : Info: [tls]     (other): before/accept initialization
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: before/accept initialization
Sat Aug 22 12:05:07 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] <<< TLS 1.0 Handshake [length 00c1], ClientHello  
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0039], ServerHello  
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 0695], Certificate  
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 00cb], ServerKeyExchange  
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] >>> TLS 1.0 Handshake [length 000e], CertificateRequest  
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: unknown state
Sat Aug 22 12:05:07 2015 : Info: [tls]     TLS_accept: Need to read more data: unknown state
Sat Aug 22 12:05:07 2015 : Debug: In SSL Handshake Phase 
Sat Aug 22 12:05:07 2015 : Debug: In SSL Accept mode  
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:07 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:07 2015 : Info: Finished request 100.
Sat Aug 22 12:05:07 2015 : Debug: Going to the next request
Sat Aug 22 12:05:07 2015 : Debug: Thread 3 waiting to be assigned a request
Sat Aug 22 12:05:07 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:07 2015 : Debug: Thread 4 got semaphore
Sat Aug 22 12:05:07 2015 : Debug: Thread 4 handling request 101, (21 handled so far)
Sat Aug 22 12:05:07 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authorize {
Sat Aug 22 12:05:07 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:07 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:07 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:07 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP packet type response id 164 length 6
Sat Aug 22 12:05:07 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:07 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:07 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:07 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:07 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:07 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authenticate {
Sat Aug 22 12:05:07 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:07 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:07 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:07 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:07 2015 : Info: [tls] Received TLS ACK
Sat Aug 22 12:05:07 2015 : Info: [tls] ACK handshake fragment handler
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_verify returned 1 
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_process returned 13 
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = handled
Sat Aug 22 12:05:07 2015 : Info: +} # group authenticate = handled
Sat Aug 22 12:05:07 2015 : Info: Finished request 101.
Sat Aug 22 12:05:07 2015 : Debug: Going to the next request
Sat Aug 22 12:05:07 2015 : Debug: Thread 4 waiting to be assigned a request
Sat Aug 22 12:05:07 2015 : Debug: Waking up in 0.9 seconds.
Sat Aug 22 12:05:07 2015 : Debug: Thread 1 got semaphore
Sat Aug 22 12:05:07 2015 : Debug: Thread 1 handling request 102, (21 handled so far)
Sat Aug 22 12:05:07 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authorize {
Sat Aug 22 12:05:07 2015 : Info: ++[preprocess] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[chap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[mschap] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[digest] = noop
Sat Aug 22 12:05:07 2015 : Info: [suffix] No '@' in User-Name = "selen.kjonca", looking up realm NULL
Sat Aug 22 12:05:07 2015 : Info: [suffix] No such realm "NULL"
Sat Aug 22 12:05:07 2015 : Info: ++[suffix] = noop
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP packet type response id 165 length 13
Sat Aug 22 12:05:07 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = updated
Sat Aug 22 12:05:07 2015 : Info: [files] users: Matched entry selen.kjonca at line 12
Sat Aug 22 12:05:07 2015 : Info: ++[files] = ok
Sat Aug 22 12:05:07 2015 : Info: ++[expiration] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[logintime] = noop
Sat Aug 22 12:05:07 2015 : Info: ++[pap] = noop
Sat Aug 22 12:05:07 2015 : Info: +} # group authorize = updated
Sat Aug 22 12:05:07 2015 : Info: Found Auth-Type = EAP
Sat Aug 22 12:05:07 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group authenticate {
Sat Aug 22 12:05:07 2015 : Info: [eap] Request found, released from the list
Sat Aug 22 12:05:07 2015 : Info: [eap] EAP/tls
Sat Aug 22 12:05:07 2015 : Info: [eap] processing type tls
Sat Aug 22 12:05:07 2015 : Info: [tls] Authenticate
Sat Aug 22 12:05:07 2015 : Info: [tls] processing EAP-TLS
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_verify returned 7 
Sat Aug 22 12:05:07 2015 : Info: [tls] Done initial handshake
Sat Aug 22 12:05:07 2015 : Info: [tls] <<< Unknown TLS version [length 0005]  
Sat Aug 22 12:05:07 2015 : Info: [tls] <<< TLS 1.0 Alert [length 0002], fatal unknown_ca  
Sat Aug 22 12:05:07 2015 : Error: TLS Alert read:fatal:unknown CA
Sat Aug 22 12:05:07 2015 : Error:     TLS_accept: failed in unknown state
Sat Aug 22 12:05:07 2015 : Error: rlm_eap: SSL error error:14094418:SSL routines:ssl3_read_bytes:tlsv1 alert unknown ca
Sat Aug 22 12:05:07 2015 : Error: SSL: SSL_read failed inside of TLS (-1), TLS session fails.
Sat Aug 22 12:05:07 2015 : Debug: TLS receive handshake failed during operation
Sat Aug 22 12:05:07 2015 : Info: [tls] eaptls_process returned 4 
Sat Aug 22 12:05:07 2015 : Info: [eap] Handler failed in EAP/tls
Sat Aug 22 12:05:07 2015 : Info: [eap] Failed in EAP select
Sat Aug 22 12:05:07 2015 : Info: ++[eap] = invalid
Sat Aug 22 12:05:07 2015 : Info: +} # group authenticate = invalid
Sat Aug 22 12:05:07 2015 : Info: Failed to authenticate the user.
Sat Aug 22 12:05:07 2015 : Auth: Login incorrect (TLS Alert read:fatal:unknown CA): [selen.kjonca] (from client ni port 2 cli 00-08-22-4F-62-54)
Sat Aug 22 12:05:07 2015 : Info: Using Post-Auth-Type REJECT
Sat Aug 22 12:05:07 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Sat Aug 22 12:05:07 2015 : Info: +group REJECT {
Sat Aug 22 12:05:07 2015 : Info: [attr_filter.access_reject] 	expand: %{User-Name} -> selen.kjonca
Sat Aug 22 12:05:07 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Sat Aug 22 12:05:07 2015 : Info: ++[attr_filter.access_reject] = updated
Sat Aug 22 12:05:07 2015 : Info: +} # group REJECT = updated
Sat Aug 22 12:05:07 2015 : Info: Delaying reject of request 102 for 1 seconds
Sat Aug 22 12:05:07 2015 : Debug: Going to the next request
Sat Aug 22 12:05:07 2015 : Debug: Thread 1 waiting to be assigned a request
Sat Aug 22 12:05:08 2015 : Info: Sending delayed reject for request 102
Sat Aug 22 12:05:08 2015 : Debug: Waking up in 1.7 seconds.
Sat Aug 22 12:05:10 2015 : Info: Cleaning up request 95 ID 252 with timestamp +1718
Sat Aug 22 12:05:10 2015 : Info: Cleaning up request 96 ID 253 with timestamp +1718
Sat Aug 22 12:05:10 2015 : Info: Cleaning up request 97 ID 254 with timestamp +1718
Sat Aug 22 12:05:10 2015 : Debug: Waking up in 1.0 seconds.
Sat Aug 22 12:05:11 2015 : Info: Cleaning up request 98 ID 255 with timestamp +1718
Sat Aug 22 12:05:11 2015 : Debug: Waking up in 1.2 seconds.
Sat Aug 22 12:05:12 2015 : Info: Cleaning up request 99 ID 0 with timestamp +1720
Sat Aug 22 12:05:12 2015 : Info: Cleaning up request 100 ID 1 with timestamp +1720
Sat Aug 22 12:05:12 2015 : Info: Cleaning up request 101 ID 2 with timestamp +1720
Sat Aug 22 12:05:12 2015 : Debug: Waking up in 1.0 seconds.
Sat Aug 22 12:05:13 2015 : Info: Cleaning up request 102 ID 3 with timestamp +1720
Sat Aug 22 12:05:13 2015 : Info: Ready to process requests.

-- 
http://wolnelektury.pl/wesprzyj/teraz/
share, n.:
	To give in, endure humiliation.

Strange things with android phone

kjonca＠o2.pl