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 ....
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.
Thanks Alan - in the process of building 3.0.23 for our machine.
On 27/09/2021 13:17, Adrian Smith via Freeradius-Users wrote:
TBH I'd suggest using the head of v3.0.x from git, or the packages at ....
Thanks Alan - in the process of building 3.0.23 for our machine.
Do what Alan said and use v3.0.x HEAD, or the Network RADIUS packages. You'll likely hit issues with 3.0.23. -- Matthew
TBH I'd suggest using the head of v3.0.x from git, or the packages at ....
Thanks Alan - in the process of building 3.0.23 for our machine.
Do what Alan said and use v3.0.x HEAD, or the Network RADIUS packages. You'll likely hit issues with 3.0.23.
We are struggling a little bit: build/objs/src/main/tls.o: In function `set_ecdh_curve': /freeradius-server/src/main/tls.c:3446: undefined reference to `SSL_CTX_set1_curves_list' /freeradius-server/src/main/tls.c:3453: undefined reference to `SSL_CTX_set_ecdh_auto' /freeradius-server/src/main/tls.c:3461: undefined reference to `SSL_CTX_set_ecdh_auto' collect2: ld returned 1 exit status make: *** [build/bin/radeapclient] Error 1 This looks like new code in .22 onwards? [root@fad446045112 /]# openssl version OpenSSL 1.0.1e-fips 11 Feb 2013 Regards, Adrian
On Sep 28, 2021, at 7:37 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
We are struggling a little bit:
build/objs/src/main/tls.o: In function `set_ecdh_curve': /freeradius-server/src/main/tls.c:3446: undefined reference to `SSL_CTX_set1_curves_list' /freeradius-server/src/main/tls.c:3453: undefined reference to `SSL_CTX_set_ecdh_auto' /freeradius-server/src/main/tls.c:3461: undefined reference to `SSL_CTX_set_ecdh_auto' collect2: ld returned 1 exit status make: *** [build/bin/radeapclient] Error 1
This looks like new code in .22 onwards?
Yes.
[root@fad446045112 /]# openssl version OpenSSL 1.0.1e-fips 11 Feb 2013
The above code is protected by a "ifdef" which checks for OpenSSL 1.0.2. So it looks like you have two versions of OpenSSL installed, which is not recommended. But for your purposes, just delete the code, or ifdef it out. Or, install a more recent version of OpenSSL. For v4, we're limiting OpenSSL to 1.1.0 or later. Because everything else is very very old. Alan DeKok.
More logs from v3.0.x build: Seems like the failing client is not sending enough of something for "ClientKeyExchange" ? GOOD: Tue Sep 28 15:34:29 2021 : Debug: (58) EAP-Message = 0x0201001a01616e6f6e796d6f757340776966692e62742e636f6d Tue Sep 28 15:34:29 2021 : Debug: (58) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (58) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (58) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (58) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (58) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (58) eap: Peer sent EAP Response (code 2) ID 1 length 26 Tue Sep 28 15:34:29 2021 : Debug: (58) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Tue Sep 28 15:34:29 2021 : Debug: (58) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (58) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (58) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (58) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (58) eap: Peer sent packet with method EAP Identity (1) Tue Sep 28 15:34:29 2021 : Debug: (58) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (58) eap_ttls: (TLS) Initiating new session Tue Sep 28 15:34:29 2021 : Debug: (58) eap_ttls: [eaptls start] = request Tue Sep 28 15:34:29 2021 : Debug: (58) eap: Sending EAP Request (code 1) ID 2 length 6 Tue Sep 28 15:34:29 2021 : Debug: (58) eap: EAP session adding &reply:State = 0x3c25b1763c27a401 Tue Sep 28 15:34:29 2021 : Debug: (58) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (58) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (58) EAP-Message = 0x010200061520 Tue Sep 28 15:34:29 2021 : Debug: (59) EAP-Message = 0x02020093150016030100880100008403036b8ccf4287c117042ff12cecb990104034ec94b610f72bb701aadfcc0cbff16d000028c02bc02fc02cc030cca9cca8c009c013c00ac014c007c011009c009d002f003c0035003d0005000a0100003300170000ff01000100000a00080006001d00170018000b00020100000d00140012040308040401050308050501080606010201 Tue Sep 28 15:34:29 2021 : Debug: (59) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (59) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (59) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (59) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (59) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Peer sent EAP Response (code 2) ID 2 length 147 Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (59) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (59) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (59) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (59) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Expiring EAP session with state 0x3c25b1763c27a401 Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Finished EAP session with state 0x3c25b1763c27a401 Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Previous EAP request found for state 0x3c25b1763c27a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) EAP Got final fragment (141 bytes) Tue Sep 28 15:34:29 2021 : WARNING: (59) eap_ttls: (TLS) EAP Total received record fragments (141 bytes), does not equal expected expected data length (0 bytes) Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [UNKWN] - before/accept initialization (24576) Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [UNKWN] - Server before/accept initialization (24576) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 136 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 01 00 00 84 03 03 6b 8c cf 42 87 c1 17 04 2f f1 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 2c ec b9 90 10 40 34 ec 94 b6 10 f7 2b b7 01 aa Tue Sep 28 15:34:29 2021 : Debug: (TLS) df cc 0c bf f1 6d 00 00 28 c0 2b c0 2f c0 2c c0 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 30 cc a9 cc a8 c0 09 c0 13 c0 0a c0 14 c0 07 c0 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 11 00 9c 00 9d 00 2f 00 3c 00 35 00 3d 00 05 00 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 0a 01 00 00 33 00 17 00 00 ff 01 00 01 00 00 0a Tue Sep 28 15:34:29 2021 : Debug: (TLS) 00 08 00 06 00 1d 00 17 00 18 00 0b 00 02 01 00 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 00 0d 00 14 00 12 04 03 08 04 04 01 05 03 08 05 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 05 01 08 06 06 01 02 01 Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) recv TLS 1.2 Handshake, ClientHello Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3RCH_A] - Server SSLv3 read client hello A (8464) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 57 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 02 00 00 35 03 03 61 53 27 f5 95 a0 33 ce 16 69 Tue Sep 28 15:34:29 2021 : Debug: (TLS) b8 d2 7a 54 d8 4c 30 7b ad 8a 7c 5b 3b 94 b0 7b Tue Sep 28 15:34:29 2021 : Debug: (TLS) d6 35 83 39 42 f3 00 c0 2f 00 00 0d ff 01 00 01 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 00 00 0b 00 04 03 00 01 02 Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerHello Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3WSH_A] - Server SSLv3 write server hello A (8496) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 3008 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 0b 00 0b bc 00 0b b9 00 07 0d 30 82 07 09 30 82 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 05 f1 a0 03 02 01 02 02 10 0d f3 63 d2 a0 4a 2b Tue Sep 28 15:34:29 2021 : Debug: (TLS) 91 39 ad bb 87 ea 27 73 06 30 0d 06 09 2a 86 48 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 86 f7 0d 01 01 0b 05 00 30 61 31 0b 30 09 06 03 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 55 04 06 13 02 55 53 31 15 30 13 06 03 55 04 0a Tue Sep 28 15:34:29 2021 : Debug: (TLS) 13 0c 44 69 67 69 43 65 72 74 20 49 6e 63 31 19 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 30 17 06 03 55 04 0b 13 10 77 77 77 2e 64 69 67 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 69 63 65 72 74 2e 63 6f 6d 31 20 30 1e 06 03 55 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 04 03 13 17 47 65 6f 54 72 75 73 74 20 45 56 20 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 52 53 41 20 43 41 20 32 30 31 38 30 1e 17 0d 32 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 31 30 39 30 37 30 30 30 30 30 30 5a 17 0d 32 32 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 31 30 30 37 32 33 35 39 35 39 5a 30 81 a7 31 1d Tue Sep 28 15:34:29 2021 : Debug: (TLS) 30 1b 06 03 55 04 0f 0c 14 50 72 69 76 61 74 65 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 20 4f 72 67 61 6e 69 7a 61 74 69 6f 6e 31 13 30 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 11 06 0b 2b 06 01 04 01 82 37 3c 02 01 03 13 02 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 47 42 31 11 30 0f 06 03 55 04 05 13 08 30 31 38 Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) send TLS 1.2 Handshake, Certificate Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3WSC_A] - Server SSLv3 write certificate A (8512) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 333 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 0c 00 01 49 03 00 17 41 04 d9 f6 29 80 79 36 8a Tue Sep 28 15:34:29 2021 : Debug: (TLS) c0 8e 51 60 85 d3 f9 14 5e 0a 8c 61 d8 74 f1 db Tue Sep 28 15:34:29 2021 : Debug: (TLS) 08 b0 6a f0 02 9a b2 c6 78 30 fc 0f 17 54 30 72 Tue Sep 28 15:34:29 2021 : Debug: (TLS) ee b3 d6 14 d5 64 f0 dd fd 58 87 4a 11 ad 27 df Tue Sep 28 15:34:29 2021 : Debug: (TLS) 50 16 f6 3d 16 51 00 c1 8d 04 01 01 00 21 c8 eb Tue Sep 28 15:34:29 2021 : Debug: (TLS) 49 2e 54 c4 a8 c8 5f b9 11 d8 5c 1a b7 d2 0a 29 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 79 58 8e 35 f4 9d 11 40 59 75 76 74 d5 76 84 b4 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 83 22 c4 88 d6 b3 3d d7 d8 f9 05 06 a2 97 8c c6 Tue Sep 28 15:34:29 2021 : Debug: (TLS) d2 5f c6 36 19 c0 3d fc 1c 0e ce d9 f3 52 28 e7 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 0d ed 70 20 4b cb 0e 9e c9 8e 1f 43 5e f9 52 89 Tue Sep 28 15:34:29 2021 : Debug: (TLS) de 12 47 0e d9 41 d8 ec fe cc fa ec 11 d3 17 53 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 41 5f 25 58 de bf 2f e3 59 57 40 f8 cb 71 76 f0 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 37 00 0e d0 7f 5e 6a 6c 9c 24 65 d3 00 5e 2e 8b Tue Sep 28 15:34:29 2021 : Debug: (TLS) 12 69 ec 2f 83 c1 7e 94 3a 4c 24 c6 e6 ba 1f 47 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 8c 7e fd 44 ed 58 bd d5 ae ea 86 a1 1f 15 5f 3e Tue Sep 28 15:34:29 2021 : Debug: (TLS) 51 bf 0e 90 25 91 a2 f8 5e 04 6a a2 f5 f1 43 a0 Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerKeyExchange Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3WSKEA] - Server SSLv3 write key exchange A (8528) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 4 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 0e 00 00 00 Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerHelloDone Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3WSD_A] - Server SSLv3 write server done A (8560) Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Handshake state [3FLUSH] - Server SSLv3 flush data (8448) Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Server : Need to read more data: SSLv3 read client certificate A Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) Server : Need to read more data: SSLv3 read client certificate A Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) In Handshake Phase Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: (TLS) got 3422 bytes of data Tue Sep 28 15:34:29 2021 : Debug: (59) eap_ttls: [eaptls process] = handled Tue Sep 28 15:34:29 2021 : Debug: (59) eap: Sending EAP Request (code 1) ID 3 length 1004 Tue Sep 28 15:34:29 2021 : Debug: (59) eap: EAP session adding &reply:State = 0x3c25b1763d26a401 Tue Sep 28 15:34:29 2021 : Debug: (59) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (59) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (59) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (59) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (59) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (59) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (59) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (59) EAP-Message = 0x010303ec15c000000d5e1603030039020000350303615327f595a033ce1669b8d27a54d84c307bad8a7c5b3b94b07bd635833942f300c02f00000dff01000100000b0004030001021603030bc00b000bbc000bb900070d30820709308205f1a00302010202100df363d2a04a2b9139adbb87ea277306300d06092a864886f70d01010b05003061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e0603550403131747656f5472757374204556205253412043412032303138301e170d3231303930373030303030305a170d3232313030373233353935395a3081a7311d301b060355040f0c1450726976617465204f7267616e697a6174696f6e31133011060b2b0601040182373c020103130247423111300f060355040513083031383030303030310b3009060355040613024742310f300d060355040713064c4f4e444f4e31273025060355 Tue Sep 28 15:34:29 2021 : Debug: (60) EAP-Message = 0x020300061500 Tue Sep 28 15:34:29 2021 : Debug: (60) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (60) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (60) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (60) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (60) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (60) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (60) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (60) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (60) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (60) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Peer sent EAP Response (code 2) ID 3 length 6 Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (60) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (60) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (60) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (60) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Expiring EAP session with state 0x3c25b1763d26a401 Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Finished EAP session with state 0x3c25b1763d26a401 Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Previous EAP request found for state 0x3c25b1763d26a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:34:29 2021 : Debug: (60) eap_ttls: [eaptls process] = handled Tue Sep 28 15:34:29 2021 : Debug: (60) eap: Sending EAP Request (code 1) ID 4 length 1004 Tue Sep 28 15:34:29 2021 : Debug: (60) eap: EAP session adding &reply:State = 0x3c25b1763e21a401 Tue Sep 28 15:34:29 2021 : Debug: (60) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (60) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (60) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (60) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (60) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (60) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (60) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (60) EAP-Message = 0x010403ec15c000000d5e7445565253414341323031382e63726c304a0603551d2004433041300b06096086480186fd6c02013032060567810c01013029302706082b06010505070201161b687474703a2f2f7777772e64696769636572742e636f6d2f435053307706082b06010505070101046b3069302606082b06010505073001861a687474703a2f2f7374617475732e67656f74727573742e636f6d303f06082b060105050730028633687474703a2f2f636163657274732e67656f74727573742e636f6d2f47656f547275737445565253414341323031382e637274300c0603551d130101ff040230003082017d060a2b06010401d6790204020482016d0482016901670076002979bef09e393921f056739f63a577e5be577d9c600af8f94d5d265c255dc7840000017bbf4d231a0000040300473045022041122335cba6bd40b15ec820242e05b3b1665bd8edae96969fa2fe09f8042055022100c3d9216089a4e6ac428476a00d1f400915c2eec4c58bc019 Tue Sep 28 15:34:29 2021 : Debug: (61) EAP-Message = 0x020400061500 Tue Sep 28 15:34:29 2021 : Debug: (61) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (61) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (61) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (61) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (61) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (61) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (61) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (61) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (61) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (61) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Peer sent EAP Response (code 2) ID 4 length 6 Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (61) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (61) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (61) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (61) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Expiring EAP session with state 0x3c25b1763e21a401 Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Finished EAP session with state 0x3c25b1763e21a401 Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Previous EAP request found for state 0x3c25b1763e21a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:34:29 2021 : Debug: (61) eap_ttls: [eaptls process] = handled Tue Sep 28 15:34:29 2021 : Debug: (61) eap: Sending EAP Request (code 1) ID 5 length 1004 Tue Sep 28 15:34:29 2021 : Debug: (61) eap: EAP session adding &reply:State = 0x3c25b1763f20a401 Tue Sep 28 15:34:29 2021 : Debug: (61) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (61) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (61) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (61) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (61) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (61) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (61) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (61) EAP-Message = 0x010503ec15c000000d5e636572742e636f6d312b30290603550403132244696769436572742048696768204173737572616e636520455620526f6f74204341301e170d3137313130363132323234365a170d3237313130363132323234365a3061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e0603550403131747656f547275737420455620525341204341203230313830820122300d06092a864886f70d01010105000382010f003082010a0282010100cc1c466d2f2a8c9b016d78e2eb87e7f236ca3c3c3a76c1aeb4573cc9539d179e1e6ed09dde9d7a2c797111872bbe33eb705c332edf796eab2e0024eef22cefb2890c3cdf11861e672dee789f6dfef118ea42f0d2cfd8fcf86eafc97d6f815875544b68f699f3ab55448e685bb38ebf66d3c78787452076f9a1520c2fa2fe84ec4f036f8fb931fdf217629468d1c70923903e637a Tue Sep 28 15:34:29 2021 : Debug: (62) EAP-Message = 0x020500061500 Tue Sep 28 15:34:29 2021 : Debug: (62) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (62) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (62) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (62) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (62) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (62) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (62) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (62) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (62) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (62) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Peer sent EAP Response (code 2) ID 5 length 6 Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (62) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (62) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (62) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (62) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Expiring EAP session with state 0x3c25b1763f20a401 Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Finished EAP session with state 0x3c25b1763f20a401 Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Previous EAP request found for state 0x3c25b1763f20a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:34:29 2021 : Debug: (62) eap_ttls: [eaptls process] = handled Tue Sep 28 15:34:29 2021 : Debug: (62) eap: Sending EAP Request (code 1) ID 6 length 450 Tue Sep 28 15:34:29 2021 : Debug: (62) eap: EAP session adding &reply:State = 0x3c25b1763823a401 Tue Sep 28 15:34:29 2021 : Debug: (62) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (62) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (62) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (62) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (62) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (62) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (62) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (62) EAP-Message = 0x010601c2158000000d5e2eb52aacbc415c2f6c7d7fb65b1483f621ed0472e54d817ea3163ec429f2851e7f1aa4976d1a150966ae2669b94d9bede2c4f91d56be5fef569a145bdf2a2f36e12d763db2ecfa4e624abeee137b5a401db2135ba63acf4e2785fd62f9160303014d0c0001490300174104d9f6298079368ac08e516085d3f9145e0a8c61d874f1db08b06af0029ab2c67830fc0f17543072eeb3d614d564f0ddfd58874a11ad27df5016f63d165100c18d0401010021c8eb492e54c4a8c85fb911d85c1ab7d20a2979588e35f49d114059757674d57684b48322c488d6b33dd7d8f90506a2978cc6d25fc63619c03dfc1c0eced9f35228e70ded70204bcb0e9ec98e1f435ef95289de12470ed941d8ecfeccfaec11d31753415f2558debf2fe3595740f8cb7176f037000ed07f5e6a6c9c2465d3005e2e8b1269ec2f83c17e943a4c24c6e6ba1f478c7efd44ed58bdd5aeea86a11f155f3e51bf0e902591a2f85e046aa2f5f143a05050a5ac68121166fb2c20 Tue Sep 28 15:34:29 2021 : Debug: (63) EAP-Message = 0x02060084150016030300461000004241049b11238073ae97867ab2e63a109163a77e8ba252d5caa95472fe2d25b1061ed003ade597f1d2b269a2ed2929651d766a9888e38a9f4c6e46d06565f0ae1984db14030300010116030300280000000000000000d5f12667ca406c2198e57c7e66af0d75f6a7f2d7b6aabded75e26d41e168f902 Tue Sep 28 15:34:29 2021 : Debug: (63) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (63) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (63) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (63) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (63) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (63) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (63) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (63) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (63) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (63) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Peer sent EAP Response (code 2) ID 6 length 132 Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (63) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (63) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (63) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (63) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Expiring EAP session with state 0x3c25b1763823a401 Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Finished EAP session with state 0x3c25b1763823a401 Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Previous EAP request found for state 0x3c25b1763823a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 70 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 10 00 00 42 41 04 9b 11 23 80 73 ae 97 86 7a b2 Tue Sep 28 15:34:29 2021 : Debug: (TLS) e6 3a 10 91 63 a7 7e 8b a2 52 d5 ca a9 54 72 fe Tue Sep 28 15:34:29 2021 : Debug: (TLS) 2d 25 b1 06 1e d0 03 ad e5 97 f1 d2 b2 69 a2 ed Tue Sep 28 15:34:29 2021 : Debug: (TLS) 29 29 65 1d 76 6a 98 88 e3 8a 9f 4c 6e 46 d0 65 Tue Sep 28 15:34:29 2021 : Debug: (TLS) 65 f0 ae 19 84 db Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) recv TLS 1.2 Handshake, ClientKeyExchange Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [3RCKEA] - Server SSLv3 read client key exchange A (8592) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 1 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 01 Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) recv TLS 1.2 ChangeCipherSpec Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 16 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 14 00 00 0c 4c b3 58 ab f9 dc e7 65 ad 29 dd 43 Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) recv TLS 1.2 Handshake, Finished Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [3RFINA] - Server SSLv3 read finished A (8640) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 1 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 01 Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) send TLS 1.2 ChangeCipherSpec Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [3WCCSA] - Server SSLv3 write change cipher spec A (8656) Tue Sep 28 15:34:29 2021 : Debug: (TLS) Received 16 bytes of TLS data Tue Sep 28 15:34:29 2021 : Debug: (TLS) 14 00 00 0c 1c 01 88 5b 98 2e e0 1f e8 41 b4 e0 Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) send TLS 1.2 Handshake, Finished Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [3WFINA] - Server SSLv3 write finished A (8672) Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [3FLUSH] - Server SSLv3 flush data (8448) Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Handshake state [SSLOK] - SSL negotiation finished successfully (3) Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) Connection Established Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256" Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: TLS-Session-Version = "TLS 1.2" Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: (TLS) got 51 bytes of data Tue Sep 28 15:34:29 2021 : Debug: (63) eap_ttls: [eaptls process] = handled Tue Sep 28 15:34:29 2021 : Debug: (63) eap: Sending EAP Request (code 1) ID 7 length 61 Tue Sep 28 15:34:29 2021 : Debug: (63) eap: EAP session adding &reply:State = 0x3c25b1763922a401 Tue Sep 28 15:34:29 2021 : Debug: (63) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (63) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) recv TLS 1.2 ChangeCipherSpec" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, Finished" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 ChangeCipherSpec" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Finished" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256" Tue Sep 28 15:34:29 2021 : Debug: (63) TLS-Session-Version = "TLS 1.2" Tue Sep 28 15:34:29 2021 : Debug: (63) EAP-Message = 0x0107003d158000000033140303000101160303002888771f857698d39d804c7bd7812736b6cbd6f3c7f7fbe578fc8838c7e19a8676f59f7d48642578e7 Tue Sep 28 15:34:29 2021 : Debug: (64) EAP-Message = 0x020700b7150017030300ac000000000000000174e1f011c4e0c5f5b0a093cdd5baa06feb4a8ed34f4dfed11aaf5d9765d012facf7420c3828112b588e59e068663412cfa12a569099f40e67f8d44bc3ca32692e48a358c24e8a15c9c95552a48b9b3a40e2452913135c107c478f9bafb6269fa3f43142cd3ff1f3b3f9f767cf357c086f09a45bdac3cc5514166f95036b1b82f11d7b3868668c1845d02a607fb4aea520f75af246c2e9cd93e368a36e4cbcf281af93c23 Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientKeyExchange" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 ChangeCipherSpec" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, Finished" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 ChangeCipherSpec" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Finished" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES128-GCM-SHA256" Tue Sep 28 15:34:29 2021 : Debug: (64) &session-state:TLS-Session-Version = "TLS 1.2" Tue Sep 28 15:34:29 2021 : Debug: (64) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (64) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:34:29 2021 : Debug: (64) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:34:29 2021 : Debug: (64) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Peer sent EAP Response (code 2) ID 7 length 183 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Continuing tunnel setup Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (64) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Expiring EAP session with state 0x3c25b1763922a401 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Finished EAP session with state 0x3c25b1763922a401 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Previous EAP request found for state 0x3c25b1763922a401, released from the list Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: Authenticate Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: [eaptls process] = ok Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: Session established. Proceeding to decode tunneled attributes Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: Got tunneled request Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: User-Name = "passpoint/ff28935f-ecd9-4ea4-8567-24f27ff57e92" Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: MS-CHAP-Challenge = 0x58d465bc668c4a0f2815ce9a8beb7d19 Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: MS-CHAP2-Response = 0x3b00a9913bdba8e206457c5c29650b52252d0000000000000000855dd883b98cce3d8782d0f3e52e2f873d641bab052f6468 Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: FreeRADIUS-Proxied-To = 127.0.0.1 Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) eap: No EAP-Message, not doing EAP Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) [eap] = noop Tue Sep 28 15:34:29 2021 : Debug: (64) eap_ttls: Tunneled authentication will be proxied to passpoint Tue Sep 28 15:34:29 2021 : WARNING: (64) eap: Tunneled session will be proxied. Not doing EAP Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) [eap] = handled Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[post-proxy]: calling eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Doing post-proxy callback Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Passing reply from proxy back into the tunnel Tue Sep 28 15:34:29 2021 : Debug: (64) eap: post-auth returns 2 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Got reply 2 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Got tunneled Access-Accept Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Reply was OK Tue Sep 28 15:34:29 2021 : Debug: (64) eap: (TLS) KEYLOG: CLIENT_RANDOM 6B8CCF4287C117042FF12CECB990104034EC94B610F72BB701AADFCC0CBFF16D 0D276126B4A1054DC000E614F33D6F4EC36B4CD8542DE624CFD652980FBD6BFD7A5EFEDE024D94E8D9F6D99E07846B4F Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Sending EAP Success (code 3) ID 7 length 4 Tue Sep 28 15:34:29 2021 : Debug: (64) eap: Freeing handler Tue Sep 28 15:34:29 2021 : Debug: (64) modsingle[post-proxy]: returned from eap (rlm_eap) Tue Sep 28 15:34:29 2021 : Debug: (64) [eap] = ok Tue Sep 28 15:34:29 2021 : Debug: (64) Found Auth-Type = eap Tue Sep 28 15:34:29 2021 : Debug: (64) rest: --> Calling-Station-Id=30-ab-6a-20-dc-f9&Access-Request=User-Name = "anonymous@wifi.bt.com", Chargeable-User-Identity = 0x04, Operator-Name = "1wifi.bt.com", Location-Capable = Civic-Location, Calling-Station-Id = "30-ab-6a-20-dc-f9", Called-Station-Id = "BTFR-BTAP-01-AdrianSmithLink:LUK-PP-T", NAS-Port = 8, Cisco-AVPair = "audit-session-id=850027d9000000bc39f55261", Acct-Session-Id = "6152f539/30:ab:6a:20:dc:f9/3693", NAS-IP-Address = 10.204.17.4, NAS-Identifier = "baynard-cso-wlc02", Airespace-Wlan-Id = 110, Service-Type = Framed-User, Framed-MTU = 1300, NAS-Port-Type = Wireless-802.11, Tunnel-Type:0 = VLAN, Tunnel-Medium-Type:0 = IEEE-802, Tunnel-Private-Group-Id:0 = "850", EAP-Message = 0x020700b7150017030300ac000000000000000174e1f011c4e0c5f5b0a093cdd5baa06feb4a8ed34f4dfed11aaf5d9765d012facf7420c3828112b588e59e068663412cfa12a569099f40e67f8d44bc3ca32692e48a358c24e8a15c9c95552a48b9b3a40e2452913135c107c478f9bafb6269fa3f43142cd3ff1f3b3f9f767cf357c086f09a45bdac3cc5514166f95036b1b82f11d7b3868668c1845d02a607fb4aea520f75af246c2e9cd93e368a36e4cbcf281af93c23, State = 0x3c25b1763922a4015dae8f1fa5b64301, Message-Authenticator = 0xfdfec1f60b8fb487ee688a3feb7cf211, BTOpenzone-Gateway-Type = "WLC", Event-Timestamp = "Sep 28 2021 15:34:29 BST", EAP-Type = TTLS, Realm = "passpoint", Module-Failure-Message = "Warning: Found 2 auth-types on request for user 'anonymous@wifi.bt.com'", Module-Failure-Message = "Failed retrieving values required to evaluate condition"&Access-Accept=User-Name = "passpoint/ff28935f-ecd9-4ea4-8567-24f27ff57e92", Cisco-AVPair = "accounting-list=ACCT_CAR", Cisco-SSG-Account-Info = "NTAL_Roaming_No_Redirect", Cisco-SSG-Account-Info = "ATAL_Roaming_No_Redirect", Acct-Interim-Interval = 180, Session-Timeout = 3600, Idle-Timeout = 300, REST-HTTP-Status-Code = 200, MS-MPPE-Recv-Key = 0x5d7f571dcb80a072d9c9d0f88eb2bc0af8ac19c4cc6fcfb83d341d8d8c178db6, MS-MPPE-Send-Key = 0x19e9dafcae24edda70739b9c331dd592096fece8b7a22d52f234a709e783e366, EAP-MSK = 0x5d7f571dcb80a072d9c9d0f88eb2bc0af8ac19c4cc6fcfb83d341d8d8c178db619e9dafcae24edda70739b9c331dd592096fece8b7a22d52f234a709e783e366, EAP-EMSK = 0xb6c10c7f856579d564df18bbf6622562a9b88f1d1b32500c6279055e5d350522cd24bc7beb504aae214e6fe9b28f660198e1e160a63f7c4fcb485689fe53dca1, EAP-Session-Id = 0x156b8ccf4287c117042ff12cecb990104034ec94b610f72bb701aadfcc0cbff16d615327f595a033ce1669b8d27a54d84c307bad8a7c5b3b94b07bd635833942f3, EAP-Message = 0x03070004, Message-Authenticator = 0x00000000000000000000000000000000, REST-HTTP-Status-Code = 204 Tue Sep 28 15:34:29 2021 : Debug: (64) policy remove_reply_message_if_eap { Tue Sep 28 15:34:29 2021 : Debug: (64) if (&reply:EAP-Message && &reply:Reply-Message) { Tue Sep 28 15:34:29 2021 : Debug: (64) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE Tue Sep 28 15:34:29 2021 : Debug: (64) } # policy remove_reply_message_if_eap = noop Tue Sep 28 15:34:29 2021 : Debug: (64) EAP-Message = 0x03070004 BAD: Tue Sep 28 15:27:32 2021 : Debug: (2) EAP-Message = 0x0201001a01616e6f6e796d6f757340776966692e62742e636f6d Tue Sep 28 15:27:32 2021 : Debug: (2) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (2) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (2) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (2) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (2) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (2) eap: Peer sent EAP Response (code 2) ID 1 length 26 Tue Sep 28 15:27:32 2021 : Debug: (2) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Tue Sep 28 15:27:32 2021 : Debug: (2) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (2) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (2) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (2) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (2) eap: Peer sent packet with method EAP Identity (1) Tue Sep 28 15:27:32 2021 : Debug: (2) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (2) eap_ttls: (TLS) Initiating new session Tue Sep 28 15:27:32 2021 : Debug: (2) eap_ttls: [eaptls start] = request Tue Sep 28 15:27:32 2021 : Debug: (2) eap: Sending EAP Request (code 1) ID 2 length 6 Tue Sep 28 15:27:32 2021 : Debug: (2) eap: EAP session adding &reply:State = 0xeed9b711eedba2bc Tue Sep 28 15:27:32 2021 : Debug: (2) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (2) [eap] = handled Tue Sep 28 15:27:32 2021 : Debug: (2) EAP-Message = 0x010200061520 Tue Sep 28 15:27:32 2021 : Debug: (3) EAP-Message = 0x020200891500160301007e0100007a0303c013eff805c8ff5648cfe81778dd7ef17eee7ea6cf41229a5d455b994885203b00001ec02bc02fc02cc030cca9cca8c009c013c00ac014009c009d002f0035000a0100003300170000ff01000100000a00080006001d00170018000b00020100000d00140012040308040401050308050501080606010201 Tue Sep 28 15:27:32 2021 : Debug: (3) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (3) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (3) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (3) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (3) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Peer sent EAP Response (code 2) ID 2 length 137 Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Continuing tunnel setup Tue Sep 28 15:27:32 2021 : Debug: (3) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (3) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (3) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (3) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Expiring EAP session with state 0xeed9b711eedba2bc Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Finished EAP session with state 0xeed9b711eedba2bc Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Previous EAP request found for state 0xeed9b711eedba2bc, released from the list Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: Authenticate Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) EAP Got final fragment (131 bytes) Tue Sep 28 15:27:32 2021 : WARNING: (3) eap_ttls: (TLS) EAP Total received record fragments (131 bytes), does not equal expected expected data length (0 bytes) Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [UNKWN] - before/accept initialization (24576) Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [UNKWN] - Server before/accept initialization (24576) Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 126 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 01 00 00 7a 03 03 c0 13 ef f8 05 c8 ff 56 48 cf Tue Sep 28 15:27:32 2021 : Debug: (TLS) e8 17 78 dd 7e f1 7e ee 7e a6 cf 41 22 9a 5d 45 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 5b 99 48 85 20 3b 00 00 1e c0 2b c0 2f c0 2c c0 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 30 cc a9 cc a8 c0 09 c0 13 c0 0a c0 14 00 9c 00 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 9d 00 2f 00 35 00 0a 01 00 00 33 00 17 00 00 ff Tue Sep 28 15:27:32 2021 : Debug: (TLS) 01 00 01 00 00 0a 00 08 00 06 00 1d 00 17 00 18 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 00 0b 00 02 01 00 00 0d 00 14 00 12 04 03 08 04 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 04 01 05 03 08 05 05 01 08 06 06 01 02 01 Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) recv TLS 1.2 Handshake, ClientHello Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3RCH_A] - Server SSLv3 read client hello A (8464) Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 57 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 02 00 00 35 03 03 61 53 26 54 30 24 05 e6 1b da Tue Sep 28 15:27:32 2021 : Debug: (TLS) 5f 3f 25 a2 61 14 39 96 93 1d 0f 11 33 d1 4a 32 Tue Sep 28 15:27:32 2021 : Debug: (TLS) bd c5 73 d9 1d bc 00 c0 2f 00 00 0d ff 01 00 01 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 00 00 0b 00 04 03 00 01 02 Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerHello Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3WSH_A] - Server SSLv3 write server hello A (8496) Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 3008 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 0b 00 0b bc 00 0b b9 00 07 0d 30 82 07 09 30 82 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 05 f1 a0 03 02 01 02 02 10 0d f3 63 d2 a0 4a 2b Tue Sep 28 15:27:32 2021 : Debug: (TLS) 91 39 ad bb 87 ea 27 73 06 30 0d 06 09 2a 86 48 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 86 f7 0d 01 01 0b 05 00 30 61 31 0b 30 09 06 03 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 55 04 06 13 02 55 53 31 15 30 13 06 03 55 04 0a Tue Sep 28 15:27:32 2021 : Debug: (TLS) 13 0c 44 69 67 69 43 65 72 74 20 49 6e 63 31 19 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 30 17 06 03 55 04 0b 13 10 77 77 77 2e 64 69 67 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 69 63 65 72 74 2e 63 6f 6d 31 20 30 1e 06 03 55 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 04 03 13 17 47 65 6f 54 72 75 73 74 20 45 56 20 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 52 53 41 20 43 41 20 32 30 31 38 30 1e 17 0d 32 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 31 30 39 30 37 30 30 30 30 30 30 5a 17 0d 32 32 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 31 30 30 37 32 33 35 39 35 39 5a 30 81 a7 31 1d Tue Sep 28 15:27:32 2021 : Debug: (TLS) 30 1b 06 03 55 04 0f 0c 14 50 72 69 76 61 74 65 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 20 4f 72 67 61 6e 69 7a 61 74 69 6f 6e 31 13 30 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 11 06 0b 2b 06 01 04 01 82 37 3c 02 01 03 13 02 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 47 42 31 11 30 0f 06 03 55 04 05 13 08 30 31 38 Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) send TLS 1.2 Handshake, Certificate Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3WSC_A] - Server SSLv3 write certificate A (8512) Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 333 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 0c 00 01 49 03 00 17 41 04 36 27 fc 36 51 e9 47 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 62 1f ab 7c 3c b6 db 0c a1 ae 18 ba 48 a2 6d 67 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 57 91 42 f5 13 6f 16 7b 86 86 68 b1 c1 d9 7c 10 Tue Sep 28 15:27:32 2021 : Debug: (TLS) b0 cf e8 c6 20 25 b9 8f 7e 98 29 84 3c 9d 1b 08 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 4e b5 5e d4 7a 9d 0d 21 8c 04 01 01 00 8d 28 27 Tue Sep 28 15:27:32 2021 : Debug: (TLS) de d6 18 fa 12 83 cb a1 91 58 a9 a3 29 fb e9 2e Tue Sep 28 15:27:32 2021 : Debug: (TLS) dc 8d be 7d 6c 75 d1 dd a5 0c 2a c2 ed 06 9d 31 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 75 b4 0a e5 d4 77 ff 99 da 30 e6 b7 11 ca 1d bb Tue Sep 28 15:27:32 2021 : Debug: (TLS) 7b f6 0d 2d 02 ad 93 d2 79 64 b6 03 9d 86 31 9e Tue Sep 28 15:27:32 2021 : Debug: (TLS) 3d 43 af 11 29 ff a3 85 a7 24 24 5e c4 cf ac 4c Tue Sep 28 15:27:32 2021 : Debug: (TLS) 5c 21 1c 34 04 c9 a1 f4 6f e9 60 54 83 5d e1 fc Tue Sep 28 15:27:32 2021 : Debug: (TLS) d5 a8 10 8a 7b a9 dd 10 59 29 b6 cf c7 81 1c a3 Tue Sep 28 15:27:32 2021 : Debug: (TLS) b7 87 d6 ab a1 8c 1f 71 69 d9 38 f9 b0 9a 69 ea Tue Sep 28 15:27:32 2021 : Debug: (TLS) 33 6e c4 84 0c 93 2c d8 cb 19 27 ee 49 8b c4 fe Tue Sep 28 15:27:32 2021 : Debug: (TLS) d3 2d 6c 22 13 bb 62 db 12 17 d1 19 8e ba de 86 Tue Sep 28 15:27:32 2021 : Debug: (TLS) 30 e5 f3 77 02 15 4f 26 a6 94 6f bb 6f 04 72 a2 Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerKeyExchange Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3WSKEA] - Server SSLv3 write key exchange A (8528) Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 4 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 0e 00 00 00 Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) send TLS 1.2 Handshake, ServerHelloDone Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3WSD_A] - Server SSLv3 write server done A (8560) Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Handshake state [3FLUSH] - Server SSLv3 flush data (8448) Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Server : Need to read more data: SSLv3 read client certificate A Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) Server : Need to read more data: SSLv3 read client certificate A Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) In Handshake Phase Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: (TLS) got 3422 bytes of data Tue Sep 28 15:27:32 2021 : Debug: (3) eap_ttls: [eaptls process] = handled Tue Sep 28 15:27:32 2021 : Debug: (3) eap: Sending EAP Request (code 1) ID 3 length 1004 Tue Sep 28 15:27:32 2021 : Debug: (3) eap: EAP session adding &reply:State = 0xeed9b711efdaa2bc Tue Sep 28 15:27:32 2021 : Debug: (3) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (3) [eap] = handled Tue Sep 28 15:27:32 2021 : Debug: (3) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (3) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (3) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (3) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (3) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (3) EAP-Message = 0x010303ec15c000000d5e160303003902000035030361532654302405e61bda5f3f25a261143996931d0f1133d14a32bdc573d91dbc00c02f00000dff01000100000b0004030001021603030bc00b000bbc000bb900070d30820709308205f1a00302010202100df363d2a04a2b9139adbb87ea277306300d06092a864886f70d01010b05003061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e0603550403131747656f5472757374204556205253412043412032303138301e170d3231303930373030303030305a170d3232313030373233353935395a3081a7311d301b060355040f0c1450726976617465204f7267616e697a6174696f6e31133011060b2b0601040182373c020103130247423111300f060355040513083031383030303030310b3009060355040613024742310f300d060355040713064c4f4e444f4e31273025060355 Tue Sep 28 15:27:32 2021 : Debug: (4) EAP-Message = 0x020300061500 Tue Sep 28 15:27:32 2021 : Debug: (4) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (4) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (4) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (4) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (4) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (4) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (4) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (4) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (4) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (4) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Peer sent EAP Response (code 2) ID 3 length 6 Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Continuing tunnel setup Tue Sep 28 15:27:32 2021 : Debug: (4) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (4) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (4) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (4) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Expiring EAP session with state 0xeed9b711efdaa2bc Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Finished EAP session with state 0xeed9b711efdaa2bc Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Previous EAP request found for state 0xeed9b711efdaa2bc, released from the list Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: Authenticate Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:27:32 2021 : Debug: (4) eap_ttls: [eaptls process] = handled Tue Sep 28 15:27:32 2021 : Debug: (4) eap: Sending EAP Request (code 1) ID 4 length 1004 Tue Sep 28 15:27:32 2021 : Debug: (4) eap: EAP session adding &reply:State = 0xeed9b711ecdda2bc Tue Sep 28 15:27:32 2021 : Debug: (4) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (4) [eap] = handled Tue Sep 28 15:27:32 2021 : Debug: (4) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (4) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (4) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (4) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (4) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (4) EAP-Message = 0x010403ec15c000000d5e7445565253414341323031382e63726c304a0603551d2004433041300b06096086480186fd6c02013032060567810c01013029302706082b06010505070201161b687474703a2f2f7777772e64696769636572742e636f6d2f435053307706082b06010505070101046b3069302606082b06010505073001861a687474703a2f2f7374617475732e67656f74727573742e636f6d303f06082b060105050730028633687474703a2f2f636163657274732e67656f74727573742e636f6d2f47656f547275737445565253414341323031382e637274300c0603551d130101ff040230003082017d060a2b06010401d6790204020482016d0482016901670076002979bef09e393921f056739f63a577e5be577d9c600af8f94d5d265c255dc7840000017bbf4d231a0000040300473045022041122335cba6bd40b15ec820242e05b3b1665bd8edae96969fa2fe09f8042055022100c3d9216089a4e6ac428476a00d1f400915c2eec4c58bc019 Tue Sep 28 15:27:32 2021 : Debug: (5) EAP-Message = 0x020400061500 Tue Sep 28 15:27:32 2021 : Debug: (5) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (5) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (5) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (5) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (5) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (5) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (5) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (5) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (5) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (5) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Peer sent EAP Response (code 2) ID 4 length 6 Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Continuing tunnel setup Tue Sep 28 15:27:32 2021 : Debug: (5) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (5) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (5) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (5) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Expiring EAP session with state 0xeed9b711ecdda2bc Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Finished EAP session with state 0xeed9b711ecdda2bc Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Previous EAP request found for state 0xeed9b711ecdda2bc, released from the list Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: Authenticate Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:27:32 2021 : Debug: (5) eap_ttls: [eaptls process] = handled Tue Sep 28 15:27:32 2021 : Debug: (5) eap: Sending EAP Request (code 1) ID 5 length 1004 Tue Sep 28 15:27:32 2021 : Debug: (5) eap: EAP session adding &reply:State = 0xeed9b711eddca2bc Tue Sep 28 15:27:32 2021 : Debug: (5) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (5) [eap] = handled Tue Sep 28 15:27:32 2021 : Debug: (5) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (5) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (5) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (5) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (5) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (5) EAP-Message = 0x010503ec15c000000d5e636572742e636f6d312b30290603550403132244696769436572742048696768204173737572616e636520455620526f6f74204341301e170d3137313130363132323234365a170d3237313130363132323234365a3061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e0603550403131747656f547275737420455620525341204341203230313830820122300d06092a864886f70d01010105000382010f003082010a0282010100cc1c466d2f2a8c9b016d78e2eb87e7f236ca3c3c3a76c1aeb4573cc9539d179e1e6ed09dde9d7a2c797111872bbe33eb705c332edf796eab2e0024eef22cefb2890c3cdf11861e672dee789f6dfef118ea42f0d2cfd8fcf86eafc97d6f815875544b68f699f3ab55448e685bb38ebf66d3c78787452076f9a1520c2fa2fe84ec4f036f8fb931fdf217629468d1c70923903e637a Tue Sep 28 15:27:32 2021 : Debug: (6) EAP-Message = 0x020500061500 Tue Sep 28 15:27:32 2021 : Debug: (6) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (6) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (6) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (6) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (6) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (6) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (6) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (6) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (6) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (6) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Peer sent EAP Response (code 2) ID 5 length 6 Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Continuing tunnel setup Tue Sep 28 15:27:32 2021 : Debug: (6) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (6) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (6) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (6) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Expiring EAP session with state 0xeed9b711eddca2bc Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Finished EAP session with state 0xeed9b711eddca2bc Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Previous EAP request found for state 0xeed9b711eddca2bc, released from the list Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: Authenticate Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: (TLS) Peer ACKed our handshake fragment Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: (TLS) EAP Verification says request Tue Sep 28 15:27:32 2021 : Debug: (6) eap_ttls: [eaptls process] = handled Tue Sep 28 15:27:32 2021 : Debug: (6) eap: Sending EAP Request (code 1) ID 6 length 450 Tue Sep 28 15:27:32 2021 : Debug: (6) eap: EAP session adding &reply:State = 0xeed9b711eadfa2bc Tue Sep 28 15:27:32 2021 : Debug: (6) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (6) [eap] = handled Tue Sep 28 15:27:32 2021 : Debug: (6) TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (6) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (6) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (6) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (6) TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (6) EAP-Message = 0x010601c2158000000d5e2eb52aacbc415c2f6c7d7fb65b1483f621ed0472e54d817ea3163ec429f2851e7f1aa4976d1a150966ae2669b94d9bede2c4f91d56be5fef569a145bdf2a2f36e12d763db2ecfa4e624abeee137b5a401db2135ba63acf4e2785fd62f9160303014d0c00014903001741043627fc3651e947621fab7c3cb6db0ca1ae18ba48a26d67579142f5136f167b868668b1c1d97c10b0cfe8c62025b98f7e9829843c9d1b084eb55ed47a9d0d218c040101008d2827ded618fa1283cba19158a9a329fbe92edc8dbe7d6c75d1dda50c2ac2ed069d3175b40ae5d477ff99da30e6b711ca1dbb7bf60d2d02ad93d27964b6039d86319e3d43af1129ffa385a724245ec4cfac4c5c211c3404c9a1f46fe96054835de1fcd5a8108a7ba9dd105929b6cfc7811ca3b787d6aba18c1f7169d938f9b09a69ea336ec4840c932cd8cb1927ee498bc4fed32d6c2213bb62db1217d1198ebade8630e5f37702154f26a6946fbb6f0472a2aa8392498269d4a8fa1248 Tue Sep 28 15:27:32 2021 : Debug: (7) EAP-Message = 0x0206000d150015030300020250 Tue Sep 28 15:27:32 2021 : Debug: (7) &session-state:TLS-Session-Information = "(TLS) recv TLS 1.2 Handshake, ClientHello" Tue Sep 28 15:27:32 2021 : Debug: (7) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHello" Tue Sep 28 15:27:32 2021 : Debug: (7) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, Certificate" Tue Sep 28 15:27:32 2021 : Debug: (7) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerKeyExchange" Tue Sep 28 15:27:32 2021 : Debug: (7) &session-state:TLS-Session-Information = "(TLS) send TLS 1.2 Handshake, ServerHelloDone" Tue Sep 28 15:27:32 2021 : Debug: (7) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (7) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) -> TRUE Tue Sep 28 15:27:32 2021 : Debug: (7) if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) { Tue Sep 28 15:27:32 2021 : Debug: (7) } # if ((User-Name =~ /^passpoint/ || User-Name == 'anonymous@wifi.bt.com') && &EAP-Message ) = noop Tue Sep 28 15:27:32 2021 : Debug: (7) modsingle[authorize]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Peer sent EAP Response (code 2) ID 6 length 13 Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Continuing tunnel setup Tue Sep 28 15:27:32 2021 : Debug: (7) modsingle[authorize]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (7) [eap] = ok Tue Sep 28 15:27:32 2021 : Debug: (7) Found Auth-Type = eap Tue Sep 28 15:27:32 2021 : Debug: (7) modsingle[authenticate]: calling eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Expiring EAP session with state 0xeed9b711eadfa2bc Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Finished EAP session with state 0xeed9b711eadfa2bc Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Previous EAP request found for state 0xeed9b711eadfa2bc, released from the list Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Peer sent packet with method EAP TTLS (21) Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Calling submodule eap_ttls to process data Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: Authenticate Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 2 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 02 50 Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) recv TLS 1.2 Alert, fatal internal_error Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) Alert read:fatal:internal error Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) Server : Failed in SSLv3 read client certificate A Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) Failed reading from OpenSSL Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) s3_pkt.c[1275]:error:14094438:SSL routines:SSL3_READ_BYTES:tlsv1 alert internal error Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) s3_pkt.c[992]:error:140940E5:SSL routines:SSL3_READ_BYTES:ssl handshake failure Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) System call (I/O) error (-1) Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) EAP Receive handshake failed during operation Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: [eaptls process] = fail Tue Sep 28 15:27:32 2021 : ERROR: (7) eap: Failed continuing EAP TTLS (21) session. EAP sub-module failed Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Sending EAP Failure (code 4) ID 6 length 4 Tue Sep 28 15:27:32 2021 : Debug: (7) eap: Failed in EAP select Tue Sep 28 15:27:32 2021 : Debug: (7) modsingle[authenticate]: returned from eap (rlm_eap) Tue Sep 28 15:27:32 2021 : Debug: (7) [eap] = invalid Tue Sep 28 15:27:32 2021 : Debug: (7) attr_filter.access_reject: EAP-Message = 0x04060004 allowed by EAP-Message =* 0x Tue Sep 28 15:27:32 2021 : Debug: (7) attr_filter.access_reject: Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules Tue Sep 28 15:27:33 2021 : Debug: (7) EAP-Message = 0x04060004
On Sep 28, 2021, at 10:57 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
More logs from v3.0.x build:
Seems like the failing client is not sending enough of something for "ClientKeyExchange" ? ... Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Continuing ... Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Peer sent flags --- Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Verification says ok Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) EAP Done initial handshake Tue Sep 28 15:27:32 2021 : Debug: (TLS) Received 2 bytes of TLS data Tue Sep 28 15:27:32 2021 : Debug: (TLS) 02 50 Tue Sep 28 15:27:32 2021 : Debug: (7) eap_ttls: (TLS) recv TLS 1.2 Alert, fatal internal_error Tue Sep 28 15:27:32 2021 : ERROR: (7) eap_ttls: (TLS) Alert read:fatal:internal error
The client is sending that alert to the server. So there's some internal error on the client. What is that error? Ask the client. :( FreeRADIUS can only report the error and drop the connection. You might try upgrading OpenSSL and/or checking the list of ciphers, digests, etc. If you're running OpenSSL from 2013, it will default to encryption methods which have likely been deprecated and/or forbidden in recent versions of Windows. Try using a new VM with a newer version of OpenSSL. If that works, then the failure is some magic with an 8 year-old version of OpenSSL. Alan DeKok.
You might try upgrading OpenSSL and/or checking the list of ciphers, digests, etc. If you're running OpenSSL from 2013, it will default to encryption methods which have likely been deprecated and/or forbidden in recent versions of Windows.
Try using a new VM with a newer version of OpenSSL. If that works, then the failure is some magic with an 8 year-old version of OpenSSL.
What's the highest version of openssl I can use when building FreeRadius?
On Sep 30, 2021, at 10:29 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
What's the highest version of openssl I can use when building FreeRadius?
OpenSSL 3.0.0 was just released. But the APIs changed, so I don't recommend that. Anything in the OpenSSL 1.1.x stream is fine. Alan DeKok.
Just as a follow up to this...... We were using a wifi config file to configure the devices and by using adb logcat we established that the realm being used did not match the DNS name of the server certificate. Some versions of Android are more sensitive to this than others. Hopefully this might help someone else in the future. Thanks for the continued support. -----Original Message----- From: Alan DeKok <aland@deployingradius.com> Sent: 30 September 2021 15:34 To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Cc: Smith,AP,Adrian,TLW4 R <adrian.p.smith@bt.com> Subject: Re: EAP TTLS woes On Sep 30, 2021, at 10:29 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
What's the highest version of openssl I can use when building FreeRadius?
OpenSSL 3.0.0 was just released. But the APIs changed, so I don't recommend that. Anything in the OpenSSL 1.1.x stream is fine. Alan DeKok.
On Oct 18, 2021, at 4:57 AM, Adrian Smith via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
Just as a follow up to this......
We were using a wifi config file to configure the devices and by using adb logcat we established that the realm being used did not match the DNS name of the server certificate. Some versions of Android are more sensitive to this than others.
The newer WBA standards mandate certificate checking. It was rather random / unimplemented before that. Arran did some tests a while ago. We have a writeup here: https://networkradius.com/articles/2021/08/04/wifi-spoofing.html It takes a *long* time to fix these issues. Alan DeKok.
participants (3)
-
adrian.p.smith＠bt.com -
Alan DeKok -
Matthew Newton