Certificate verification failed, error 19 (self signed certificate in certificate chain)
Michael Zintakis
michael.zintakis
Mon Mar 12 08:40:09 PDT 2012
I hope I am posting this in the right ML!
I have a pretty "standard" setup, which involves remote machines/mobile
phones/tablets authenticating against a wireless router, which in turn
is using RADIUS on a separate machine on the same network. The
authentication mechanism is by using TTLS/TLS (EAP) with the option of
requesting the server (RADIUS) certificate as well.
Initially - when a client tries to connect for the first time - this
works without any glitches and the client is authenticated first time.
After exactly 60 minutes, however, the wpa_supplicant tries to
"re-negotiate" the connection for some reason and I get the above error,
after which the client is briefly disconnected!
When wpa_supplicant tries to re-authenticate again approximately 30
seconds after the above disconnection, the authentication succeeds
(using the same certificate/credentials which were rejected
previously!). Judging by the wpa_supplicant logs, a "handshake" is made
approximately every 10 minutes and this always succeeds.
This disconnection is extremely annoying and as I stated above - it
happens, without fail, every 60 minutes, which means the client gets
disconnected every hour no matter what!
I tried to fix this by employing a variety of "tweaks" - none of them
successfully, unfortunately:
1. I included the CA certificate in the client's p12 file so that the
whole certificate chain is present;
2. I have "disabled" the "ca_cert" parameter in the wpa_supplicant.conf
file - then re-authentication works, but the CA certificate is
completely ignored (I have a subject match in my wpa_supplicant.conf
file and no matter what is put there, wpa_supplicant completely ignores
it when ca_cert parameter is disabled).
As the ca_cert is a certificate from a certificate authority, I expect
the certificate chain to be 1 certificate deep, thus the certificate in
question is always self-signed. Why is the wpa_supplicant then
complaining, given also the fact that when it tries the same process 30
seconds later - it succeeds?! Have I missed something in my setup?
Would it be possible to either a) fix the above error and stay connected
for longer than 60 minutes at a time; or b) extend this re-negotiation
time from 60 minutes to a bit longer than that so that the client does
not get disconnected every hour?
This is my client (wpa_supplicant) log after the initial connection
negotiation succeeded and before the 60 minutes re-negotiation fails:
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Group rekeying completed with
00:1a:1d:1a:7b:c6 [GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-STARTED EAP authentication
started]
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-METHOD EAP vendor 0 method
21 (TTLS) selected]
W/wpa_supplicant( 582): TLS: Certificate verification failed, error 19
(self signed certificate in certificate chain) depth 1 for
'/C=DE/ST=XX/L=XX/O=XX/emailAddress=XX/CN=XX'
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-FAILURE EAP authentication
failed]
E/wpa_supplicant( 582): Set_key: Wrong Key
E/wpa_supplicant( 582): Set_key: Wrong Key
E/wpa_supplicant( 582): Set_key: Wrong Key
E/wpa_supplicant( 582): Set_key: Wrong Key
E/wpa_supplicant( 582): Set_key: Wrong Key
V/WifiMonitor( 467): Event [CTRL-EVENT-DISCONNECTED - Disconnect event
- remove keys]
V/WifiStateTracker( 467): New network state is DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=0]
V/WifiStateTracker( 467): Changing supplicant state: COMPLETED ==>
DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=2]
V/WifiStateTracker( 467): Changing supplicant state: DISCONNECTED ==>
SCANNING
W/wpa_supplicant( 582): Failed to initiate AP scan.
V/WifiMonitor( 467): Event [Trying to associate with 00:1a:1d:1a:7b:c6
(SSID='lsIXSw2l' freq=2452 MHz)]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=3]
V/WifiStateTracker( 467): Changing supplicant state: SCANNING ==>
ASSOCIATING
D/WifiStateTracker( 467): Reset connections and stopping DHCP
D/WifiStateTracker( 467): Disabling interface
V/WifiMonitor( 467): Event [Authentication with 00:1a:1d:1a:7b:c6 timed
out.]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=0]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATING ==>
DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=2]
V/WifiStateTracker( 467): Changing supplicant state: DISCONNECTED ==>
SCANNING
V/WifiMonitor( 467): Event [Trying to associate with 00:1a:1d:1a:7b:c6
(SSID='lsIXSw2l' freq=2452 MHz)]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=3]
V/WifiStateTracker( 467): Changing supplicant state: SCANNING ==>
ASSOCIATING
D/WifiStateTracker( 467): Reset connections and stopping DHCP
D/WifiStateTracker( 467): Disabling interface
V/WifiMonitor( 467): Event [Authentication with 00:1a:1d:1a:7b:c6 timed
out.]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=0]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATING ==>
DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=2]
V/WifiStateTracker( 467): Changing supplicant state: DISCONNECTED ==>
SCANNING
V/WifiMonitor( 467): Event [Trying to associate with 00:1a:1d:1a:7b:c6
(SSID='lsIXSw2l' freq=2452 MHz)]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=3]
V/WifiStateTracker( 467): Changing supplicant state: SCANNING ==>
ASSOCIATING
D/WifiStateTracker( 467): Reset connections and stopping DHCP
D/WifiStateTracker( 467): Disabling interface
V/WifiMonitor( 467): Event [Authentication with 00:1a:1d:1a:7b:c6 timed
out.]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=0]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATING ==>
DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=2]
V/WifiStateTracker( 467): Changing supplicant state: DISCONNECTED ==>
SCANNING
V/WifiMonitor( 467): Event [Trying to associate with 00:1a:1d:1a:7b:c6
(SSID='lsIXSw2l' freq=2452 MHz)]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=3]
V/WifiStateTracker( 467): Changing supplicant state: SCANNING ==>
ASSOCIATING
D/WifiStateTracker( 467): Reset connections and stopping DHCP
D/WifiStateTracker( 467): Disabling interface
V/WifiMonitor( 467): Event [Authentication with 00:1a:1d:1a:7b:c6 timed
out.]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=0]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATING ==>
DISCONNECTED
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=2]
V/WifiStateTracker( 467): Changing supplicant state: DISCONNECTED ==>
SCANNING
V/WifiMonitor( 467): Event [Trying to associate with 00:1a:1d:1a:7b:c6
(SSID='lsIXSw2l' freq=2452 MHz)]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=3]
V/WifiStateTracker( 467): Changing supplicant state: SCANNING ==>
ASSOCIATING
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=4]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATING ==>
ASSOCIATED
V/WifiMonitor( 467): Event [Associated with 00:1a:1d:1a:7b:c6]
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-STARTED EAP authentication
started]
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-METHOD EAP vendor 0 method
21 (TTLS) selected]
D/WifiStateTracker( 467): Reset connections and stopping DHCP
D/WifiStateTracker( 467): Disabling interface
V/WifiMonitor( 467): Event [CTRL-EVENT-EAP-SUCCESS EAP authentication
completed successfully]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=5]
V/WifiStateTracker( 467): Changing supplicant state: ASSOCIATED ==>
FOUR_WAY_HANDSHAKE
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=5]
V/WifiStateTracker( 467): Changing supplicant state: FOUR_WAY_HANDSHAKE
==> FOUR_WAY_HANDSHAKE
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6]
V/WifiStateTracker( 467): Changing supplicant state: FOUR_WAY_HANDSHAKE
==> GROUP_HANDSHAKE
V/WifiMonitor( 467): Event [WPA: Key negotiation completed with
00:1a:1d:1a:7b:c6 [PTK=CCMP GTK=CCMP]]
V/WifiMonitor( 467): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7]
V/WifiStateTracker( 467): Changing supplicant state: GROUP_HANDSHAKE
==> COMPLETED
V/WifiMonitor( 467): Event [CTRL-EVENT-CONNECTED - Connection to
00:1a:1d:1a:7b:c6 completed (reauth) [id=0 id_str=]]
V/WifiStateTracker( 467): New network state is CONNECTED
V/WifiStateTracker( 467): Static IP configuration succeeded
This is the error I get from RADIUS when re-authentication fails:
Sun Mar 11 22:06:42 2012 : Error: TLS Alert read:fatal:unknown CA
Sun Mar 11 22:06:42 2012 : Error: TLS_accept: failed in SSLv3 read
client certificate A
Sun Mar 11 22:06:42 2012 : Error: rlm_eap: SSL error error:14094418:SSL
routines:SSL3_READ_BYTES:tlsv1 alert unknown ca
Sun Mar 11 22:06:42 2012 : Error: SSL: SSL_read failed inside of TLS
(-1), TLS session fails.
This is the error I get from the wireless router for the same period:
Mar 11 22:06:44 wrt1 daemon.warn hostapd: wlan0: STA 00:1a:1d:1a:7b:c6
IEEE 802.1X: authentication failed - EAP type: 21 (TTLS)
More information about the Hostap
mailing list