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