I am testing EAP TTLS with Android and finding some mixed results. Using identical WifiConfig on the devices I see an error on some: Thu Sep 23 15:01:12 2021 : Debug: (4808) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4808) eap_ttls: Initiating new EAP-TLS session Thu Sep 23 15:01:12 2021 : Debug: (4808) eap_ttls: [eaptls start] = request Thu Sep 23 15:01:12 2021 : Debug: (4809) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: Authenticate Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: Peer sent flags --- Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: Got final TLS record fragment (131 bytes) Thu Sep 23 15:01:12 2021 : WARNING: (4809) eap_ttls: Total received TLS record fragments (131 bytes), does not equal indicated TLS record length (0 bytes) Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: [eaptls verify] = ok Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: Done initial handshake Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: (other): before/accept initialization Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: before/accept initialization Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: <<< recv TLS 1.1 [length 007e] Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 read client hello A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: >>> send TLS 1.1 [length 0039] Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 write server hello A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: >>> send TLS 1.1 [length 0bc0] Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 write certificate A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: >>> send TLS 1.1 [length 014b] Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 write key exchange A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: >>> send TLS 1.1 [length 0004] Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 write server done A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: SSLv3 flush data Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: In SSL Handshake Phase Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: In SSL Accept mode Thu Sep 23 15:01:12 2021 : Debug: (4809) eap_ttls: [eaptls process] = handled Thu Sep 23 15:01:12 2021 : Debug: (4810) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: Authenticate Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: Peer sent flags --- Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: [eaptls verify] = request Thu Sep 23 15:01:12 2021 : Debug: (4810) eap_ttls: [eaptls process] = handled Thu Sep 23 15:01:12 2021 : Debug: (4811) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: Authenticate Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: Peer sent flags --- Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: [eaptls verify] = request Thu Sep 23 15:01:12 2021 : Debug: (4811) eap_ttls: [eaptls process] = handled Thu Sep 23 15:01:12 2021 : Debug: (4812) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: Authenticate Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: Peer sent flags --- Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: [eaptls verify] = request Thu Sep 23 15:01:12 2021 : Debug: (4812) eap_ttls: [eaptls process] = handled Thu Sep 23 15:01:12 2021 : Debug: (4813) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: Authenticate Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: Peer sent flags --- Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: [eaptls verify] = ok Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: Done initial handshake Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: <<< recv TLS 1.1 [length 0002] Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: TLS Alert read:fatal:internal error Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: TLS_accept: Failed in SSLv3 read client certificate A Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: Failed in __FUNCTION__ (SSL_read) Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: s3_pkt.c[1275]:error:14094438:SSL routines:SSL3_READ_BYTES:tlsv1 alert internal error Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: s3_pkt.c[992]:error:140940E5:SSL routines:SSL3_READ_BYTES:ssl handshake failure Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: System call (I/O) error (-1) Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: TLS receive handshake failed during operation Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: [eaptls process] = fail The working device shows this log: Thu Sep 23 15:07:35 2021 : Debug: (4844) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4844) eap_ttls: Initiating new EAP-TLS session Thu Sep 23 15:07:35 2021 : Debug: (4844) eap_ttls: [eaptls start] = request Thu Sep 23 15:07:35 2021 : Debug: (4845) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: Got final TLS record fragment (141 bytes) Thu Sep 23 15:07:35 2021 : WARNING: (4845) eap_ttls: Total received TLS record fragments (141 bytes), does not equal indicated TLS record length (0 bytes) Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: [eaptls verify] = ok Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: Done initial handshake Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: (other): before/accept initialization Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: before/accept initialization Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: <<< recv TLS 1.1 [length 0088] Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 read client hello A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: >>> send TLS 1.1 [length 0039] Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 write server hello A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: >>> send TLS 1.1 [length 0bc0] Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 write certificate A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: >>> send TLS 1.1 [length 014b] Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 write key exchange A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: >>> send TLS 1.1 [length 0004] Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 write server done A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: SSLv3 flush data Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: In SSL Handshake Phase Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: In SSL Accept mode Thu Sep 23 15:07:35 2021 : Debug: (4845) eap_ttls: [eaptls process] = handled Thu Sep 23 15:07:35 2021 : Debug: (4846) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: [eaptls verify] = request Thu Sep 23 15:07:35 2021 : Debug: (4846) eap_ttls: [eaptls process] = handled Thu Sep 23 15:07:35 2021 : Debug: (4847) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: [eaptls verify] = request Thu Sep 23 15:07:35 2021 : Debug: (4847) eap_ttls: [eaptls process] = handled Thu Sep 23 15:07:35 2021 : Debug: (4848) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: Peer ACKed our handshake fragment Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: [eaptls verify] = request Thu Sep 23 15:07:35 2021 : Debug: (4848) eap_ttls: [eaptls process] = handled Thu Sep 23 15:07:35 2021 : Debug: (4849) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: [eaptls verify] = ok Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: Done initial handshake Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: <<< recv TLS 1.1 [length 0046] Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: TLS_accept: SSLv3 read client key exchange A Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: <<< recv TLS 1.1 [length 0001] Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: <<< recv TLS 1.1 [length 0010] Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: TLS_accept: SSLv3 read finished A Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: >>> send TLS 1.1 [length 0001] Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: TLS_accept: SSLv3 write change cipher spec A Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: >>> send TLS 1.1 [length 0010] Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: TLS_accept: SSLv3 write finished A Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: TLS_accept: SSLv3 flush data Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: (other): SSL negotiation finished successfully Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: SSL Connection Established Thu Sep 23 15:07:35 2021 : Debug: (4849) eap_ttls: [eaptls process] = handled Thu Sep 23 15:07:35 2021 : Debug: (4850) eap: Calling submodule eap_ttls to process data Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Authenticate Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Continuing EAP-TLS Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Peer sent flags --- Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: [eaptls verify] = ok Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Done initial handshake Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: [eaptls process] = ok Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Session established. Proceeding to decode tunneled attributes Thu Sep 23 15:07:35 2021 : Debug: (4850) eap_ttls: Got tunneled request Any clues appreciated. Adrian Smith
On Sep 27, 2021, at 5:28 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
I am testing EAP TTLS with Android and finding some mixed results.
Using identical WifiConfig on the devices I see an error on some: ... Thu Sep 23 15:01:12 2021 : Debug: (4813) eap_ttls: <<< recv TLS 1.1 [length 0002] Thu Sep 23 15:01:12 2021 : ERROR: (4813) eap_ttls: TLS Alert read:fatal:internal error
Hmm... useful errors. :( TBH I'd suggest using the head of v3.0.x from git, or the packages at http://packages.networkradius.com You're running 3.0.21 or earlier, and 3.0.22 added a lot more TLS debugging messages. So it's much easier to tell what's going on. Right now, all we know is that it's "magic OpenSSL stuff". Alan DeKok.
participants (2)
-
adrian.p.smith@bt.com -
Alan DeKok