Unable to connect to api.github.com

[justmobilize]

CircuitPython version

Most recent 9.0.0 build

Code/REPL

import os
import ssl
import time
import board
import socketpool
import wifi
import adafruit_requests

print("------------------------------")
print(os.uname())

ssid = os.getenv("CIRCUITPY_WIFI_SSID")
password = os.getenv("CIRCUITPY_WIFI_PASSWORD")

print("Connecting to WiFi...")
while not wifi.radio.connected:
  wifi.radio.connect(ssid, password)

pool = socketpool.SocketPool(wifi.radio)
ssl_context = ssl.create_default_context()

requests = adafruit_requests.Session(pool, ssl_context)

urls = [
  "http://wifitest.adafruit.com/testwifi/index.html",
  "http://www.adafruit.com/api/quotes.php",
  "https://api.github.com",
]

import time

s = time.monotonic()

try:
  for url in urls:
    print(url)
    r = requests.get(url, timeout=300)
    r.close()
except Exception as e:
  print(e)

e = time.monotonic()

print(f"Time: {e-s} seconds")
  
print("Done!")

Behavior

Added some print statements to adafruit_requests:

------------------------------
(sysname='ESP32S3', nodename='ESP32S3', release='9.0.0', version='9.0.0-beta.0-26-gc6d195a39f on 2024-02-12', machine='FeatherS3 with ESP32S3')
Connecting to WiFi...
http://wifitest.adafruit.com/testwifi/index.html
_get_socket: start
_get_socket: try: 1
_get_socket: set timeout: 300
http://www.adafruit.com/api/quotes.php
_get_socket: start
_get_socket: try: 1
_get_socket: set timeout: 300
_get_socket: start
_get_socket: try: 1
_get_socket: set timeout: 300
https://api.github.com
_get_socket: start
_get_socket: try: 1
_get_socket: set timeout: 300
_get_socket: socket.connect - OSError: Failed SSL handshake
_get_socket: try: 2
_get_socket: _free_sockets
_get_socket: set timeout: 300
_get_socket: socket.connect - OSError: Failed SSL handshake
_get_socket: try: 3
Sending request failed
Time: 25.471 seconds
Done!

Code done running.

Description

On a ESP32S3 chip will fail with OSError: Failed SSL handshake when trying to socket.connect to api.github.com

8.2.9: works every time. Average time ~5 seconds

9.0.0-alpha.2.uf2: happens half the time: Average time ~15 seconds

9.0.0-alpha.4.uf2: MemoryError: memory allocation failed, allocating 1784 bytes on line 7

9.0.0-alpha.5.uf2: never errored: Average time ~12 seconds

9.0.0-alpha.6.uf2: always errored: Average time ~20 seconds
9.0.0-beta.0: always errored: Average time ~20 seconds
9.0.0-beta.0 from PR merge 8898: always errored: Average time ~20 seconds

Additional information

No response

[tannewt]

Here is the MBEDTLS log. I'm not sure why it is failing. Maybe outgoing buffer size?

I (265484) mbedtls: ssl_tls.c:3931 => handshake

I (265484) mbedtls: ssl_msg.c:2370 => flush output

I (265484) mbedtls: ssl_msg.c:2379 <= flush output

I (265484) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_HELLO_REQUEST

I (265494) mbedtls: ssl_msg.c:2370 => flush output

I (265504) mbedtls: ssl_msg.c:2379 <= flush output

I (265504) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CLIENT_HELLO

I (265514) mbedtls: ssl_client.c:938 => write client hello

I (265524) mbedtls: ssl_msg.c:2800 => write handshake message

I (265524) mbedtls: ssl_msg.c:2960 => write record

I (265534) mbedtls: ssl_msg.c:3097 <= write record

I (265534) mbedtls: ssl_msg.c:2921 <= write handshake message

I (265544) mbedtls: ssl_client.c:1026 <= write client hello

I (265554) mbedtls: ssl_msg.c:2370 => flush output

I (265554) mbedtls: ssl_msg.c:2384 message length: zu, out_left: zu

I (265564) mbedtls: ssl_msg.c:2391 ssl->f_send() returned 215 (-0xffffff29)

I (265574) mbedtls: ssl_msg.c:2418 <= flush output

I (265584) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_SERVER_HELLO

I (265584) mbedtls: ssl_tls12_client.c:1205 => parse server hello

I (265594) mbedtls: ssl_msg.c:4134 => read record

I (265594) mbedtls: ssl_msg.c:2172 => fetch input

I (265604) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (265614) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (265614) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (265624) mbedtls: ssl_msg.c:2357 <= fetch input

I (265634) mbedtls: ssl_msg.c:2172 => fetch input

I (265634) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (265644) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (265644) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 65 (-0xffffffbf)

I (265654) mbedtls: ssl_msg.c:2357 <= fetch input

I (265664) mbedtls: ssl_msg.c:4206 <= read record

I (265674) mbedtls: ssl_tls12_client.c:1457 server hello, total extension length: zu

I (265674) mbedtls: ssl_tls12_client.c:1673 <= parse server hello

I (265684) mbedtls: ssl_msg.c:2370 => flush output

I (265694) mbedtls: ssl_msg.c:2379 <= flush output

I (265694) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_SERVER_CERTIFICATE

I (265704) mbedtls: ssl_tls.c:7522 => parse certificate

I (265714) mbedtls: ssl_msg.c:4134 => read record

I (265714) mbedtls: ssl_msg.c:2172 => fetch input

I (265724) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (265724) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (265734) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (265744) mbedtls: ssl_msg.c:2357 <= fetch input

I (265744) mbedtls: ssl_msg.c:2172 => fetch input

I (265754) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (265764) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (265764) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 2453 (-0xfffff66b)

I (265774) mbedtls: ssl_msg.c:2357 <= fetch input

I (265784) mbedtls: ssl_msg.c:4206 <= read record

I (273094) esp-x509-crt-bundle: Certificate validated
I (273104) mbedtls: ssl_tls.c:7635 <= parse certificate

I (273104) mbedtls: ssl_msg.c:2370 => flush output

I (273104) mbedtls: ssl_msg.c:2379 <= flush output

I (273114) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_SERVER_KEY_EXCHANGE

I (273114) mbedtls: ssl_tls12_client.c:2102 => parse server key exchange

I (273124) mbedtls: ssl_msg.c:4134 => read record

I (273134) mbedtls: ssl_msg.c:2172 => fetch input

I (273134) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (273144) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (273154) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (273154) mbedtls: ssl_msg.c:2357 <= fetch input

I (273164) mbedtls: ssl_msg.c:2172 => fetch input

I (273164) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (273174) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (273184) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 115 (-0xffffff8d)

I (273194) mbedtls: ssl_msg.c:2357 <= fetch input

I (273194) mbedtls: ssl_msg.c:4206 <= read record

I (273204) mbedtls: ssl_tls12_client.c:1818 ECDH curve: x25519

I (275934) mbedtls: ssl_tls12_client.c:2472 <= parse server key exchange

I (275934) mbedtls: ssl_msg.c:2370 => flush output

I (275934) mbedtls: ssl_msg.c:2379 <= flush output

I (275944) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CERTIFICATE_REQUEST

I (275944) mbedtls: ssl_tls12_client.c:2511 => parse certificate request

I (275954) mbedtls: ssl_msg.c:4134 => read record

I (275964) mbedtls: ssl_msg.c:2172 => fetch input

I (275964) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (275974) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (275974) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (275984) mbedtls: ssl_msg.c:2357 <= fetch input

I (275994) mbedtls: ssl_msg.c:2172 => fetch input

I (275994) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu

I (276004) mbedtls: ssl_msg.c:2332 in_left: zu, nb_want: zu

I (276014) mbedtls: ssl_msg.c:2335 ssl->f_recv(_timeout)() returned 4 (-0xfffffffc)

I (276024) mbedtls: ssl_msg.c:2357 <= fetch input

I (276024) mbedtls: ssl_msg.c:4206 <= read record

I (276034) mbedtls: ssl_tls12_client.c:2675 <= parse certificate request

I (276034) mbedtls: ssl_msg.c:2370 => flush output

I (276044) mbedtls: ssl_msg.c:2379 <= flush output

I (276054) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_SERVER_HELLO_DONE

I (276054) mbedtls: ssl_tls12_client.c:2686 => parse server hello done

I (276064) mbedtls: ssl_msg.c:4134 => read record

I (276074) mbedtls: ssl_msg.c:4202 reuse previously read message

I (276074) mbedtls: ssl_msg.c:4206 <= read record

I (276084) mbedtls: ssl_tls12_client.c:2714 <= parse server hello done

I (276094) mbedtls: ssl_msg.c:2370 => flush output

I (276094) mbedtls: ssl_msg.c:2379 <= flush output

I (276104) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CLIENT_CERTIFICATE

I (276114) mbedtls: ssl_tls.c:6927 => write certificate

I (276114) mbedtls: ssl_tls.c:6938 <= skip write certificate

I (276124) mbedtls: ssl_msg.c:2370 => flush output

I (276124) mbedtls: ssl_msg.c:2379 <= flush output

I (276134) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CLIENT_KEY_EXCHANGE

I (276144) mbedtls: ssl_tls12_client.c:2729 => write client key exchange

I (276344) mbedtls: ssl_msg.c:2800 => write handshake message

I (276344) mbedtls: ssl_msg.c:2960 => write record

I (276344) mbedtls: ssl_msg.c:2370 => flush output

I (276344) mbedtls: ssl_msg.c:2384 message length: zu, out_left: zu

I (276354) mbedtls: ssl_msg.c:2391 ssl->f_send() returned 42 (-0xffffffd6)

I (276364) mbedtls: ssl_msg.c:2418 <= flush output

I (276364) mbedtls: ssl_msg.c:3097 <= write record

I (276374) mbedtls: ssl_msg.c:2921 <= write handshake message

I (276384) mbedtls: ssl_tls12_client.c:3224 <= write client key exchange

I (276384) mbedtls: ssl_msg.c:2370 => flush output

I (276394) mbedtls: ssl_msg.c:2379 <= flush output

I (276394) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CERTIFICATE_VERIFY

I (276404) mbedtls: ssl_tls12_client.c:3272 => write certificate verify

I (276414) mbedtls: ssl_tls.c:6541 => derive keys

I (276424) mbedtls: ssl_tls.c:6665 => calc verify

I (276424) mbedtls: ssl_tls.c:6684 <= calc verify

I (276434) mbedtls: ssl_tls.c:6592 <= derive keys

I (276434) mbedtls: ssl_tls12_client.c:3294 <= skip write certificate verify

I (276444) mbedtls: ssl_msg.c:2370 => flush output

I (276454) mbedtls: ssl_msg.c:2379 <= flush output

I (276454) mbedtls: ssl_tls.c:3850 client state: MBEDTLS_SSL_CLIENT_CHANGE_CIPHER_SPEC

I (276464) mbedtls: ssl_msg.c:5136 => write change cipher spec

I (276474) mbedtls: ssl_msg.c:2800 => write handshake message

I (276474) mbedtls: ssl_msg.c:2960 => write record

I (276484) mbedtls: ssl_msg.c:2370 => flush output

I (276494) mbedtls: ssl_msg.c:2384 message length: zu, out_left: zu

I (276494) mbedtls: ssl_msg.c:2391 ssl->f_send() returned -80 (-0x0050)

W (276504) mbedtls: ssl_msg.c:3093 mbedtls_ssl_flush_output() returned -80 (-0x0050)

W (276514) mbedtls: ssl_msg.c:2916 ssl_write_record() returned -80 (-0x0050)

W (276524) mbedtls: ssl_msg.c:5145 mbedtls_ssl_write_handshake_msg() returned -80 (-0x0050)

I (276534) mbedtls: ssl_tls.c:3942 <= handshake

E (276534) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x0050
E (276544) esp-tls: Failed to open new connection

[jepler]

Just a note that "%zu" is intended to print a value of type size_t but this is not supported and so just "zu" is printed.

"I (265634) mbedtls: ssl_msg.c:2312 in_left: zu, nb_want: zu"

This problem almost certainly stems from the hacky way I connect esp-idf's debug printing to use circuitpython's printf implementation:

#if CIRCUITPY_CONSOLE_UART
static int vprintf_adapter(const char *fmt, va_list ap) {
    return mp_vprintf(&mp_plat_print, fmt, ap);
}   

void port_serial_early_init(void) {
    esp_log_set_vprintf(vprintf_adapter);
}
#endif                                   

[tannewt]

Ya, that seemed suspect to me. I'll fix it now and see what I get.

[jepler]

could try hacking in %z support.

diff --git a/py/mpprint.c b/py/mpprint.c
index 467371bec2..5bc920bb62 100644
--- a/py/mpprint.c
+++ b/py/mpprint.c
@@ -464,7 +464,7 @@ int mp_vprintf(const mp_print_t *print, const char *fmt, va_list args) {
         const
         #endif
         bool long_arg = false;
-        if (*fmt == 'l') {
+        if (*fmt == 'l' || *fmt == 'z') {
             ++fmt;
             #ifdef __LP64__
             long_arg = true;

[dhalbert]

I checked the commit for lib/certificates and it is the same for 8.2.9 and main. So it is not an obvious missing root cert.

[justmobilize]

I updated the test list to:

urls = [
  "http://wifitest.adafruit.com/testwifi/index.html",
  "http://www.adafruit.com/api/quotes.php",
  "https://api.github.com",
  "https://api.thingspeak.com",
  "https://opensky-network.org",
  "https://api.fitbit.com/",
  "https://discord.com/api",
  "https://id.twitch.tv",
  "https://api.twitter.com/"
  "https://youtube.googleapis.com",
]

And github is the only one that fails

[tannewt]

I'm at a loss. It looks like the server is resetting the connection after we send the client key:

I (23072) mbedtls: ssl_msg.c:2379 <= flush output

I (23082) mbedtls: ssl_tls.c:3852 client state: MBEDTLS_SSL_SERVER_HELLO_DONE

I (23082) mbedtls: ssl_tls12_client.c:2686 => parse server hello done

I (23092) mbedtls: ssl_msg.c:4134 => read record

I (23102) mbedtls: ssl_msg.c:4202 reuse previously read message

I (23102) mbedtls: ssl_msg.c:4206 <= read record

I (23112) mbedtls: ssl_tls12_client.c:2714 <= parse server hello done

I (23122) mbedtls: ssl_msg.c:2370 => flush output

I (23122) mbedtls: ssl_msg.c:2379 <= flush output

I (23132) mbedtls: ssl_tls.c:3852 client state: MBEDTLS_SSL_CLIENT_CERTIFICATE

I (23142) mbedtls: ssl_tls.c:6929 => write certificate

I (23142) mbedtls: ssl_tls.c:6940 <= skip write certificate

I (23152) mbedtls: ssl_msg.c:2370 => flush output

I (23152) mbedtls: ssl_msg.c:2379 <= flush output

I (23162) mbedtls: ssl_tls.c:3852 client state: MBEDTLS_SSL_CLIENT_KEY_EXCHANGE

I (23172) mbedtls: ssl_tls12_client.c:2729 => write client key exchange

D (23272) mbedtls: ssl_tls12_client.c:2875 value of 'ECDH: Q(X)' (255 bits) is:

D (23272) mbedtls: ssl_tls12_client.c:2875  46 81 12 6c a1 d7 c8 58 e9 91 25 ad b0 f2 01 7f

D (23272) mbedtls: ssl_tls12_client.c:2875  88 e4 62 3e 81 a4 29 1b 57 02 4f 9e 3f 3f 0d 64

D (23282) mbedtls: ssl_tls12_client.c:2875 value of 'ECDH: Q(Y)' (0 bits) is:

D (23292) mbedtls: ssl_tls12_client.c:2875  00

D (23392) mbedtls: ssl_tls12_client.c:2903 value of 'ECDH: z' (255 bits) is:

D (23392) mbedtls: ssl_tls12_client.c:2903  57 db 22 3a 28 6e 23 08 3e a4 56 b8 0a f6 fd ee

D (23402) mbedtls: ssl_tls12_client.c:2903  2d f2 b1 2d b7 9a 97 76 b3 8b 10 8a b5 87 27 62

I (23412) mbedtls: ssl_msg.c:2800 => write handshake message

I (23412) mbedtls: ssl_msg.c:2960 => write record

D (23422) mbedtls: ssl_msg.c:3044 output record: msgtype = 22, version = [3:3], msglen = 37

I (23432) mbedtls: ssl_msg.c:2370 => flush output

I (23432) mbedtls: ssl_msg.c:2384 message length: 42, out_left: 42

D (23442) lwip: lwip_send(58, data=0x3fce5f7c, size=42, flags=0x0)

D (23452) lwip: ip4_output_if: st1

D (23452) lwip: IP header:

D (23452) lwip: +-------------------------------+

D (23462) lwip: | 4 | 5 |  0x00 |        82     | (v, hl, tos, len)

D (23462) lwip: +-------------------------------+

D (23472) lwip: |       21      |000|       0   | (id, flags, offset)

D (23472) lwip: +-------------------------------+

D (23482) lwip: |  255  |    6  |    0x60a3     | (ttl, proto, chksum)

D (23492) lwip: +-------------------------------+

D (23492) lwip: |  192  |  168  |    0  |   23  | (src)

D (23502) lwip: +-------------------------------+

D (23502) lwip: |   20  |   29  |  134  |   17  | (dest)

D (23512) lwip: +-------------------------------+

D (23512) lwip: ip4_output_if: call netif->output()

D (23522) lwip: lwip_send(58) err=0 written=42

I (23522) mbedtls: ssl_msg.c:2391 ssl->f_send() returned 42 (-0xffffffd6)

D (23532) lwip: ip_input: iphdr->dest 0x1700a8c0 netif->ip_addr 0x1700a8c0 (0xa8c0, 0xa8c0, 0x17000000)

D (23542) lwip: ip4_input: packet accepted on interface st

D (23542) lwip: ip4_input: 

D (23552) lwip: IP header:

D (23552) lwip: +-------------------------------+

D (23562) lwip: | 4 | 5 |  0x00 |        40     | (v, hl, tos, len)

D (23562) lwip: +-------------------------------+

D (23572) lwip: |        0      |010|       0   | (id, flags, offset)

D (23572) lwip: +-------------------------------+

D (23582) lwip: |   52  |    6  |    0xebe2     | (ttl, proto, chksum)

D (23592) lwip: +-------------------------------+

D (23592) lwip: |   20  |   29  |  134  |   17  | (src)

D (23602) lwip: +-------------------------------+

D (23602) lwip: |  192  |  168  |    0  |   23  | (dest)

D (23612) lwip: +-------------------------------+

D (23612) lwip: ip4_input: p->len 40 p->tot_len 40

D (23622) lwip: tcp_pcb_purge

D (23622) lwip: tcp_pcb_purge: data left on ->unacked

D (23632) lwip: tcp_slowtmr: no active pcbs

I (23632) mbedtls: ssl_msg.c:2418 <= flush output

I (23642) mbedtls: ssl_msg.c:3097 <= write record

I (23642) mbedtls: ssl_msg.c:2921 <= write handshake message

I (23652) mbedtls: ssl_tls12_client.c:3224 <= write client key exchange

I (23652) mbedtls: ssl_msg.c:2370 => flush output

I (23662) mbedtls: ssl_msg.c:2379 <= flush output

I (23672) mbedtls: ssl_tls.c:3852 client state: MBEDTLS_SSL_CERTIFICATE_VERIFY

I (23672) mbedtls: ssl_tls12_client.c:3272 => write certificate verify

I (23682) mbedtls: ssl_tls.c:6543 => derive keys

I (23692) mbedtls: ssl_tls.c:6667 => calc verify

D (23692) mbedtls: ssl_tls.c:6685 dumping 'calculated verify result' (32 bytes)

D (23702) mbedtls: ssl_tls.c:6685 0000:  be b4 ab 31 33 0d f9 2d f0 f7 26 44 d8 7f 1d 17  ...13..-..&D....

D (23712) mbedtls: ssl_tls.c:6685 0010:  52 33 c3 38 6f ac 07 12 6c 87 31 d8 3f a6 76 bc  R3.8o...l.1.?.v.

I (23722) mbedtls: ssl_tls.c:6686 <= calc verify

D (23722) mbedtls: ssl_tls.c:6397 dumping 'session hash for extended master secret' (32 bytes)

D (23732) mbedtls: ssl_tls.c:6397 0000:  be b4 ab 31 33 0d f9 2d f0 f7 26 44 d8 7f 1d 17  ...13..-..&D....

D (23742) mbedtls: ssl_tls.c:6397 0010:  52 33 c3 38 6f ac 07 12 6c 87 31 d8 3f a6 76 bc  R3.8o...l.1.?.v.

D (23752) mbedtls: ssl_tls.c:6526 dumping 'premaster secret' (32 bytes)

D (23762) mbedtls: ssl_tls.c:6526 0000:  62 27 87 b5 8a 10 8b b3 76 97 9a b7 2d b1 f2 2d  b'......v...-..-

D (23772) mbedtls: ssl_tls.c:6526 0010:  ee fd f6 0a b8 56 a4 3e 08 23 6e 28 3a 22 db 57  .....V.>.#n(:".W

D (23782) mbedtls: ssl_tls.c:8275 ciphersuite = TLS-ECDHE-ECDSA-WITH-AES-128-GCM-SHA256

D (23792) mbedtls: ssl_tls.c:8277 dumping 'master secret' (48 bytes)

D (23802) mbedtls: ssl_tls.c:8277 0000:  2f 64 77 ed 5d 7a 59 e6 a5 ec 22 3a da 53 3a 38  /dw.]zY...":.S:8

D (23802) mbedtls: ssl_tls.c:8277 0010:  9d e5 3b 49 e3 71 cc a2 2a 33 f1 1f 1d de 7a f0  ..;I.q..*3....z.

D (23812) mbedtls: ssl_tls.c:8277 0020:  6a 8d 9d d7 9d 15 d6 a1 d4 bb b2 1e 8b a0 50 19  j.............P.

D (23832) mbedtls: ssl_tls.c:8399 keylen: 16, minlen: 24, ivlen: 12, maclen: 0

I (23832) mbedtls: ssl_tls.c:6594 <= derive keys

I (23842) mbedtls: ssl_tls12_client.c:3294 <= skip write certificate verify

I (23852) mbedtls: ssl_msg.c:2370 => flush output

I (23852) mbedtls: ssl_msg.c:2379 <= flush output

I (23862) mbedtls: ssl_tls.c:3852 client state: MBEDTLS_SSL_CLIENT_CHANGE_CIPHER_SPEC

I (23872) mbedtls: ssl_msg.c:5136 => write change cipher spec

I (23872) mbedtls: ssl_msg.c:2800 => write handshake message

I (23882) mbedtls: ssl_msg.c:2960 => write record

D (23882) mbedtls: ssl_msg.c:3044 output record: msgtype = 20, version = [3:3], msglen = 1

I (23892) mbedtls: ssl_msg.c:2370 => flush output

I (23902) mbedtls: ssl_msg.c:2384 message length: 6, out_left: 6

D (23902) lwip: lwip_send(58, data=0x3fce5f7c, size=6, flags=0x0)

D (23912) lwip: lwip_send(58) err=-14 written=0

I (23922) mbedtls: ssl_msg.c:2391 ssl->f_send() returned -80 (-0x0050)

W (23922) mbedtls: ssl_msg.c:3093 mbedtls_ssl_flush_output() returned -80 (-0x0050)

W (23932) mbedtls: ssl_msg.c:2916 ssl_write_record() returned -80 (-0x0050)

W (23942) mbedtls: ssl_msg.c:5145 mbedtls_ssl_write_handshake_msg() returned -80 (-0x0050)

I (23952) mbedtls: ssl_tls.c:3944 <= handshake

E (23952) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x0050
I (23962) esp-tls-mbedtls: (FFFFFFB0): UNKNOWN ERROR CODE (0050)
E (23972) esp-tls: Failed to open new connection
D (24022) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3fcbb8ec
D (24022) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3fcbb8ec
D (24032) lwip: lwip_shutdown(57, how=2)

D (24032) lwip: tcp_close: closing in 
D (24032) lwip: State: CLOSED

D (24042) lwip: lwip_close(57)

D (24042) lwip: lwip_shutdown(58, how=2)

D (24042) lwip: lwip_close(58)

[justmobilize]

Is it possible to compare to 8.2.9 to see where it's different?

[dhalbert]

[CORRECTED] Confirmed that 9.0.0-alpha.6 fails and 9.0.0-alpha.5 succeeds, so we can do a bisect in that range. Tested on both ESP32-S2 and ESP32-S3. Both show this behavior.

[justmobilize]

@dhalbert that 5 fails and 6 succeeds, or the other way around? I had 5 being successful...

Also the other strange part was how much slower it was vs 8.2.9

[dhalbert]

@dhalbert that 5 fails and 6 succeeds, or the other way around? I had 5 being successful...

Sorry that was my late-night error. Fixed.