8000 Unable to connect to api.github.com · Issue #8910 · adafruit/circuitpython · GitHub
[go: up one dir, main page]
Skip to content

Unable to connect to api.github.com #8910

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
justmobilize opened this issue Feb 13, 2024 · 14 comments · Fixed by #8924
Closed

Unable to connect to api.github.com #8910

justmobilize opened this issue Feb 13, 2024 · 14 comments · Fixed by #8924
Assignees
@dhalbert
Labels
bug espressif applies to multiple Espressif chips network
Milestone
9.0.0

Comments

@justmobilize
Copy link

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 tannewt added network espressif applies to multiple Espressif chips labels Feb 13, 2024
@tannewt tannewt added this to the 9.0.0 milestone Feb 13, 2024
@tannewt
Copy link
Member
tannewt commented Feb 13, 2024

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
Copy link
jepler commented Feb 13, 2024

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
Copy link
Member
tannewt commented Feb 13, 2024

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

@jepler
Copy link
jepler commented Feb 13, 2024

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
Copy link
Collaborator

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
Copy link
Author

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
Copy link
Member
tannewt commented Feb 13, 2024

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
Copy link
Author

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

@dhalbert
Copy link
Collaborator
dhalbert commented Feb 14, 2024 •
edited
Loading

[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
Copy link
Author

@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
Copy link
Collaborator

@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.

@dhalbert dhalbert self-assigned this Feb 14, 2024
@dhalbert
Copy link
Collaborator
dhalbert commented Feb 14, 2024 •
edited
Loading

Bisect shows api.github.com fails as of the first commit in #8686, 051ad46. So I'll look further at changes there, ESP-IDF issues, and maybe try advancing past there. The third commit in #8686 set it to exactly v5.1.2, which was needed to get it to work.

https://github.com/adafruit/circuitpython/pull/8686/commits

@justmobilize
Copy link
Author

ugh 5.1 -> 5.1.2: Showing 478 changed files with 11,490 additions and 3,813 deletions.

@dhalbert
Copy link
Collaborator

I'm getting this to work by adjusting the MBEDTLS_ECP settings. Will have a PR later.

@dhalbert dhalbert mentioned this issue Feb 15, 2024
Merged
jepler added a commit to jepler/circuitpython that r 7687 eferenced this issue Feb 15, 2024
@jepler
espressif: Use mbedtls implementation of ssl module.
b57c37c 
the mbedtls version is a bit different so there are some new #ifdefs
needed.

Tested with the ssl test from adafruit#8910
on Adafruit MatrixPortal S3 (no pico w testing done)
@jepler jepler mentioned this issue Feb 15, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@dhalbert dhalbert

Labels
bug espressif applies to multiple Espressif chips network
Projects
None yet
Milestone
9.0.0
4 participants
@tannewt @jepler @justmobilize @dhalbert
0