mbedtls_ssl_handshake errors specifying failed to open new connection (IDFGH-781)

[AadiMehta]

Description:

I am trying to send log file to the local server using esp_http_client. I am using mdns service to identify local server in the network(This part seems to be working fine). We are also using mqtt for other functionality.

9 out of 10 times the file sending succeeds but when failed, even after trying multiple times it doesn't succeeds. Logs for the ssl_handshake errors are following:

I (212340) ESP32Project.utils.networking: DATA={"type": "REQUEST", "data": "", "msg_id": "0x240ac40f4eec_29500403", "command": "health"}
I (212355) ESP32Project.utils.networking: File size to send: 2655
I (219817) wifi: bcn_timout,ap_probe_send_start
E (220818) esp-tls: mbedtls_ssl_handshake returned -0x4c
I (220819) esp-tls: Certificate verified.
E (220822) esp-tls: Failed to open new connection
E (220824) TRANS_SSL: Failed to open a new connection
E (220830) HTTP_CLIENT: Connection failed, sock < 0
E (220835) ESP32Project.utils.networking: Failed to open HTTP connection: ESP_ERR_HTTP_CONNECT
I (220850) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=37089
I (220855) ESP32Project.utils.networking: DATA={"type": "REQUEST", "data": "", "msg_id": "0x240ac40f4eec_29500403", "command": "health"}
I (220870) ESP32Project.utils.networking: File size to send: 2881
E (228061) esp-tls: mbedtls_ssl_handshake returned -0x4c
I (228062) esp-tls: Certificate verified.
E (228064) esp-tls: Failed to open new connection
E (228067) TRANS_SSL: Failed to open a new connection
E (228073) HTTP_CLIENT: Connection failed, sock < 0
E (228078) ESP32Project.utils.networking: Failed to open HTTP connection: ESP_ERR_HTTP_CONNECT
I (228093) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=13340
I (228096) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=12092
I (230500) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=30349
I (464530) ESP32Project.utils.networking: DATA={"data": "", "msg_id": "0x240ac40f4eec_83120411", "type": "REQUEST", "command": "chipInfo"}
I (464552) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=53744
I (758081) ESP32Project.utils.networking: DATA={"type": "REQUEST", "data": "", "msg_id": "0x240ac40f4eec_29500403", "command": "health"}
I (758096) ESP32Project.utils.networking: File size to send: 3501
E (758704) esp-tls: mbedtls_ssl_handshake returned -0x10
I (758704) esp-tls: Certificate verified.
E (758707) esp-tls: Failed to open new connection
E (758709) TRANS_SSL: Failed to open a new connection
E (758715) HTTP_CLIENT: Connection failed, sock < 0
E (758720) ESP32Project.utils.networking: Failed to open HTTP connection: ESP_ERR_HTTP_CONNECT
I (758735) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=31980
I (758741) ESP32Project.utils.networking: MQTT_EVENT_PUBLISHED, msg_id=26221
I (770720) ESP32Project.utils.networking: DATA={"type": "REQUEST", "data": "", "msg_id": "0x240ac40f4eec_29500403", "command": "health"}
I (770737) ESP32Project.utils.networking: File size to send: 3810
E (771331) esp-tls: mbedtls_ssl_handshake returned -0x10

Note: It does say that the certificate has been verified, so that means mdns is working as expected and esp was able to contact the local server and handshake was initiated, but then it fails saying fail to open a new connection.

[AadiMehta]

Any update on this?

[AadiMehta]

After turning on mbedtls debug I found out the issue to be at: mbedtls_ecdh_make_public() function

I (194091) mbedtls: ssl_tls.c:2763 <= flush output

I (194097) mbedtls: ssl_cli.c:2851 => write client key exchange

W (194549) mbedtls: ssl_cli.c:2912 mbedtls_ecdh_make_public() returned -16 (-0x0010)

I (194549) mbedtls: ssl_tls.c:8031 <= handshake

E (194552) esp-tls: mbedtls_ssl_handshake returned -0x10
I (194558) esp-tls: Certificate verified.
E (194565) esp-tls: Failed to open new connection
E (194568) TRANS_SSL: Failed to open a new connection
E (194573) HTTP_CLIENT: Connection failed, sock < 0
E (194579) ESP32Project.utils.networking: Failed to open HTTP connection: ESP_ERR_HTTP_CONNECT

NOTE: HTTPS requests fail only when I am trying to send some attachment to the server. Otherwise, all other HTTPS API requests are passing to the same server.

Also when I deselect ecdh ciphers from the mbedtls config, issue is no more there. I have tried enabling ecdh ciphersuite explicitly on the apache server but to no success. Please let me know if the findings are correct.

[jitin17]

@AadiMehta Can you give us some information about stack and heap consumption when you are sending some attachments with ecdh ciphers enabled?

[jitin17]

@AadiMehta This looks like a memory issue. The fact that it works on disabling ECDH reinforces the claim. Here's a similar issue. https://tls.mbed.org/discussions/bug-report-issues/mbedtls_ecdh_make_public-returned-16 Could you call esp_get_minimum_free_heap_size() in your code and respond with the heap size during the SSL handshake?

[lexus2k]

Hi All,

Definitely, I see the same issue: tls returns "0x4c" error. (I use official ESP-IDF v3.2)

Sometimes tls connection opens, but mostly it fails. From my observations, the issue happens at my home network (Asus RT-66), but I see it very rarely at the office (I believe we have some MIkrotiks). So, maybe, it relates to some network conditions. All home devices feel ok (phones, pc, tabs, laptops, etc.), but esp32 experience some issues. And the root cause is NOT memory - I logged min free heap size:

I (13528) WEB: Validating version per https://github.com/lexus2k/nixie_clock/raw/master/binaries/nixie_clock.txt
I (13548) EVENT: MIN HEAP: 169412
I (16128) EVENT: MIN HEAP: 122340
I (18708) EVENT: MIN HEAP: 119596
I (21288) EVENT: MIN HEAP: 119596
E (21418) esp-tls: mbedtls_ssl_handshake returned -0x4c
E (21418) esp-tls: Failed to open new connection
E (21418) TRANS_SSL: Failed to open a new connection
E (21418) HTTP_CLIENT: Connection failed, sock < 0
E (21428) WEB: Failed to perform HTTP GET request from https://github.com/lexus2k/nixie_clock/raw/master/binaries/nixie_clock.txt
I (23868) EVENT: MIN HEAP: 119596

[jitin17]

@lexus2k Your error condition is -0x4c which is MBEDTLS_ERR_NET_RECV_FAILED, and this is different from the error code -0x10 seen in the above-mentioned problem. MBEDTLS_ERR_NET_RECV_FAILED mostly implies some network issues. It would be helpful if you can enable mbedtls logging and do a pcap capture.

[lexus2k]

@jitin17 here are the logs, you requested:

I (18013) WEB: Validating version per https://github.com/lexus2k/nixie_clock/raw/master/binaries/nixie_clock.txt
I (18873) mbedtls: ssl_tls.c:8021 => handshake

I (18873) mbedtls: ssl_cli.c:3405 client state: 0

I (18873) mbedtls: ssl_tls.c:2751 => flush output

I (18883) mbedtls: ssl_tls.c:2763 <= flush output

I (18883) mbedtls: ssl_cli.c:3405 client state: 1

I (18893) mbedtls: ssl_tls.c:2751 => flush output

I (18893) mbedtls: ssl_tls.c:2763 <= flush output

I (18903) mbedtls: ssl_cli.c:774 => write client hello

I (18913) mbedtls: ssl_tls.c:3180 => write handshake message

I (18913) mbedtls: ssl_tls.c:3337 => write record

I (18923) mbedtls: ssl_tls.c:2751 => flush output

I (18923) mbedtls: ssl_tls.c:2770 message length: 239, out_left: 239

I (18933) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 239 (-0xffffff11)

I (18943) mbedtls: ssl_tls.c:2803 <= flush output

I (18943) mbedtls: ssl_tls.c:3470 <= write record

I (18953) mbedtls: ssl_tls.c:3314 <= write handshake message

I (18953) mbedtls: ssl_cli.c:1106 <= write client hello

I (18963) mbedtls: ssl_cli.c:3405 client state: 2

I (18973) mbedtls: ssl_tls.c:2751 => flush output

I (18973) mbedtls: ssl_tls.c:2763 <= flush output

I (18983) mbedtls: ssl_cli.c:1499 => parse server hello

I (18983) mbedtls: ssl_tls.c:4305 => read record

I (18993) mbedtls: ssl_tls.c:2532 => fetch input

I (18993) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (19433) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (19433) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (19433) mbedtls: ssl_tls.c:2738 <= fetch input

I (19443) mbedtls: ssl_tls.c:2532 => fetch input

I (19443) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 102

I (19453) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 102

I (19453) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 97 (-0xffffff9f)

I (19463) mbedtls: ssl_tls.c:2738 <= fetch input

I (19473) mbedtls: ssl_tls.c:4379 <= read record

I (19473) mbedtls: ssl_cli.c:1781 server hello, total extension length: 21

I (19483) mbedtls: ssl_cli.c:1970 <= parse server hello

I (19493) mbedtls: ssl_cli.c:3405 client state: 3

I (19493) mbedtls: ssl_tls.c:2751 => flush output

I (19503) mbedtls: ssl_tls.c:2763 <= flush output

I (19503) mbedtls: ssl_tls.c:5440 => parse certificate

I (19513) mbedtls: ssl_tls.c:4305 => read record

I (19523) mbedtls: ssl_tls.c:2532 => fetch input

I (19523) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (19533) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (19533) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (19543) mbedtls: ssl_tls.c:2738 <= fetch input

I (19553) mbedtls: ssl_tls.c:2532 => fetch input

I (19553) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 3090

I (19563) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 3090

I (19573) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 3085 (-0xfffff3f3)

I (19573) mbedtls: ssl_tls.c:2738 <= fetch input

I (19613) mbedtls: ssl_tls.c:4379 <= read record

I (19623) mbedtls: ssl_tls.c:5810 <= parse certificate

I (19623) mbedtls: ssl_cli.c:3405 client state: 4

I (19623) mbedtls: ssl_tls.c:2751 => flush output

I (19623) mbedtls: ssl_tls.c:2763 <= flush output

I (19633) mbedtls: ssl_cli.c:2317 => parse server key exchange

I (19633) mbedtls: ssl_tls.c:4305 => read record

I (19643) mbedtls: ssl_tls.c:2532 => fetch input

I (19653) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (19653) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (19663) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (19673) mbedtls: ssl_tls.c:2738 <= fetch input

I (19673) mbedtls: ssl_tls.c:2532 => fetch input

I (19683) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 338

I (19683) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 338

I (19693) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 333 (-0xfffffeb3)

I (19703) mbedtls: ssl_tls.c:2738 <= fetch input

I (19713) mbedtls: ssl_tls.c:4379 <= read record

I (19713) mbedtls: ssl_cli.c:2030 ECDH curve: secp256r1

I (19723) mbedtls: ssl_cli.c:2259 Server used SignatureAlgorithm 1

I (19723) mbedtls: ssl_cli.c:2260 Server used HashAlgorithm 4

I (19773) mbedtls: ssl_cli.c:2617 <= parse server key exchange

I (19773) mbedtls: ssl_cli.c:3405 client state: 5

I (19773) mbedtls: ssl_tls.c:2751 => flush output

I (19783) mbedtls: ssl_tls.c:2763 <= flush output

I (19783) mbedtls: ssl_cli.c:2650 => parse certificate request

I (19793) mbedtls: ssl_tls.c:4305 => read record

I (19793) mbedtls: ssl_tls.c:2532 => fetch input

I (19803) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (19813) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (19813) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (19823) mbedtls: ssl_tls.c:2738 <= fetch input

I (19833) mbedtls: ssl_tls.c:2532 => fetch input

I (19833) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 9

I (19843) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 9

I (19843) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 4 (-0xfffffffc)

I (19853) mbedtls: ssl_tls.c:2738 <= fetch input

I (19863) mbedtls: ssl_tls.c:4379 <= read record

I (19863) mbedtls: ssl_cli.c:2799 <= parse certificate request

I (19873) mbedtls: ssl_cli.c:3405 client state: 6

I (19883) mbedtls: ssl_tls.c:2751 => flush output

I (19883) mbedtls: ssl_tls.c:2763 <= flush output

I (19893) mbedtls: ssl_cli.c:2809 => parse server hello done

I (19893) mbedtls: ssl_tls.c:4305 => read record

I (19903) mbedtls: ssl_tls.c:4375 reuse previously read message

I (19913) mbedtls: ssl_tls.c:4379 <= read record

I (19913) mbedtls: ssl_cli.c:2839 <= parse server hello done

I (19923) mbedtls: ssl_cli.c:3405 client state: 7

I (19923) mbedtls: ssl_tls.c:2751 => flush output

I (19933) mbedtls: ssl_tls.c:2763 <= flush output

I (19933) mbedtls: ssl_tls.c:5323 => write certificate

I (19943) mbedtls: ssl_tls.c:5340 <= skip write certificate

I (19953) mbedtls: ssl_cli.c:3405 client state: 8

I (19953) mbedtls: ssl_tls.c:2751 => flush output

I (19963) mbedtls: ssl_tls.c:2763 <= flush output

I (19963) mbedtls: ssl_cli.c:2851 => write client key exchange

I (20693) mbedtls: ssl_tls.c:3180 => write handshake message

I (20693) mbedtls: ssl_tls.c:3337 => write record

I (20693) mbedtls: ssl_tls.c:2751 => flush output

I (20703) mbedtls: ssl_tls.c:2770 message length: 75, out_left: 75

I (20713) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 75 (-0xffffffb5)

I (20713) mbedtls: ssl_tls.c:2803 <= flush output

I (20723) mbedtls: ssl_tls.c:3470 <= write record

I (20723) mbedtls: ssl_tls.c:3314 <= write handshake message

I (20733) mbedtls: ssl_cli.c:3093 <= write client key exchange

I (20733) mbedtls: ssl_cli.c:3405 client state: 9

I (20743) mbedtls: ssl_tls.c:2751 => flush output

I (20753) mbedtls: ssl_tls.c:2763 <= flush output

I (20753) mbedtls: ssl_cli.c:3144 => write certificate verify

I (20763) mbedtls: ssl_tls.c:625 => derive keys

I (20763) mbedtls: ssl_tls.c:1202 => calc verify sha256

I (20773) mbedtls: ssl_tls.c:1208 <= calc verify

I (20783) mbedtls: ssl_tls.c:1113 <= derive keys

I (20783) mbedtls: ssl_cli.c:3165 <= skip write certificate verify

I (20793) mbedtls: ssl_cli.c:3405 client state: 10

I (20793) mbedtls: ssl_tls.c:2751 => flush output

I (20803) mbedtls: ssl_tls.c:2763 <= flush output

I (20803) mbedtls: ssl_tls.c:5826 => write change cipher spec

I (20813) mbedtls: ssl_tls.c:3180 => write handshake message

I (20823) mbedtls: ssl_tls.c:3337 => write record

I (20823) mbedtls: ssl_tls.c:2751 => flush output

I (20833) mbedtls: ssl_tls.c:2770 message length: 6, out_left: 6

I (20843) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 6 (-0xfffffffa)

I (20843) mbedtls: ssl_tls.c:2803 <= flush output

I (20853) mbedtls: ssl_tls.c:3470 <= write record

I (20853) mbedtls: ssl_tls.c:3314 <= write handshake message

I (20863) mbedtls: ssl_tls.c:5840 <= write change cipher spec

I (20873) mbedtls: ssl_cli.c:3405 client state: 11

I (20873) mbedtls: ssl_tls.c:2751 => flush output

I (20883) mbedtls: ssl_tls.c:2763 <= flush output

I (20883) mbedtls: ssl_tls.c:6345 => write finished

I (20893) mbedtls: ssl_tls.c:6170 => calc  finished tls sha256

I (20903) mbedtls: ssl_tls.c:6200 <= calc  finished

I (20903) mbedtls: ssl_tls.c:3180 => write handshake message

I (20913) mbedtls: ssl_tls.c:3337 => write record

I (20913) mbedtls: ssl_tls.c:1441 => encrypt buf

I (20923) mbedtls: ssl_tls.c:1777 <= encrypt buf

I (20933) mbedtls: ssl_tls.c:2751 => flush output

I (20933) mbedtls: ssl_tls.c:2770 message length: 45, out_left: 45

I (20943) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 45 (-0xffffffd3)

I (20953) mbedtls: ssl_tls.c:2803 <= flush output

I (20953) mbedtls: ssl_tls.c:3470 <= write record

I (20963) mbedtls: ssl_tls.c:3314 <= write handshake message

I (20963) mbedtls: ssl_tls.c:6454 <= write finished

I (20973) mbedtls: ssl_cli.c:3405 client state: 12

I (20973) mbedtls: ssl_tls.c:2751 => flush output

I (20983) mbedtls: ssl_tls.c:2763 <= flush output

I (20993) mbedtls: ssl_tls.c:5849 => parse change cipher spec

I (20993) mbedtls: ssl_tls.c:4305 => read record

I (21003) mbedtls: ssl_tls.c:2532 => fetch input

I (21003) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (21153) EVENT: MIN HEAP: 119928, CURRENT HEAP: 121756
I (22923) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (22923) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (22923) mbedtls: ssl_tls.c:2738 <= fetch input

I (22923) mbedtls: ssl_tls.c:2532 => fetch input

I (22933) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 6

I (22943) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 6

I (22943) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 1 (-0xffffffff)

I (22953) mbedtls: ssl_tls.c:2738 <= fetch input

I (22963) mbedtls: ssl_tls.c:4379 <= read record

I (22963) mbedtls: ssl_tls.c:5913 <= parse change cipher spec

I (22973) mbedtls: ssl_cli.c:3405 client state: 13

I (22973) mbedtls: ssl_tls.c:2751 => flush output

I (22983) mbedtls: ssl_tls.c:2763 <= flush output

I (22993) mbedtls: ssl_tls.c:6471 => parse finished

I (22993) mbedtls: ssl_tls.c:6170 => calc  finished tls sha256

I (23003) mbedtls: ssl_tls.c:6200 <= calc  finished

I (23003) mbedtls: ssl_tls.c:4305 => read record

I (23013) mbedtls: ssl_tls.c:2532 => fetch input

I (23013) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (23023) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (23033) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (23033) mbedtls: ssl_tls.c:2738 <= fetch input

I (23043) mbedtls: ssl_tls.c:2532 => fetch input

I (23053) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 45

I (23053) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 45

I (23063) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 40 (-0xffffffd8)

I (23073) mbedtls: ssl_tls.c:2738 <= fetch input

I (23073) mbedtls: ssl_tls.c:1790 => decrypt buf

I (23083) mbedtls: ssl_tls.c:2372 <= decrypt buf

I (23083) mbedtls: ssl_tls.c:4379 <= read record

I (23093) mbedtls: ssl_tls.c:6539 <= parse finished

I (23093) mbedtls: ssl_cli.c:3405 client state: 14

I (23103) mbedtls: ssl_tls.c:2751 => flush output

I (23113) mbedtls: ssl_tls.c:2763 <= flush output

I (23113) mbedtls: ssl_cli.c:3516 handshake: done

I (23123) mbedtls: ssl_cli.c:3405 client state: 15

I (23123) mbedtls: ssl_tls.c:2751 => flush output

I (23133) mbedtls: ssl_tls.c:2763 <= flush output

I (23133) mbedtls: ssl_tls.c:8031 <= handshake

I (23143) mbedtls: ssl_tls.c:8619 => write

I (23143) mbedtls: ssl_tls.c:3337 => write record

I (23153) mbedtls: ssl_tls.c:1441 => encrypt buf

I (23163) mbedtls: ssl_tls.c:1777 <= encrypt buf

I (23163) mbedtls: ssl_tls.c:2751 => flush output

I (23173) mbedtls: ssl_tls.c:2770 message length: 174, out_left: 174

I (23173) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 174 (-0xffffff52)

I (23183) mbedtls: ssl_tls.c:2803 <= flush output

I (23193) mbedtls: ssl_tls.c:3470 <= write record

I (23193) mbedtls: ssl_tls.c:8647 <= write

I (23883) mbedtls: ssl_tls.c:8207 => read

I (23883) mbedtls: ssl_tls.c:4305 => read record

I (23883) mbedtls: ssl_tls.c:2532 => fetch input

I (23893) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (23893) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (23903) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (23913) mbedtls: ssl_tls.c:2738 <= fetch input

I (23913) mbedtls: ssl_tls.c:2532 => fetch input

I (23923) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 1399

I (23933) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 1399

I (23933) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 1394 (-0xfffffa8e)

I (23943) mbedtls: ssl_tls.c:2738 <= fetch input

I (23963) mbedtls: ssl_tls.c:1790 => decrypt buf

I (23963) mbedtls: ssl_tls.c:2372 <= decrypt buf

I (23973) mbedtls: ssl_tls.c:4379 <= read record

I (23973) mbedtls: ssl_tls.c:8495 <= read

I (23973) mbedtls: ssl_tls.c:8207 => read

I (23983) mbedtls: ssl_tls.c:4305 => read record

I (23983) mbedtls: ssl_tls.c:2532 => fetch input

I (23993) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (23993) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (24003) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (24013) mbedtls: ssl_tls.c:2738 <= fetch input

I (24013) mbedtls: ssl_tls.c:2532 => fetch input

I (24023) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 210

I (24023) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 210

I (24033) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 205 (-0xffffff33)

I (24043) mbedtls: ssl_tls.c:2738 <= fetch input

I (24053) mbedtls: ssl_tls.c:1790 => decrypt buf

I (24053) mbedtls: ssl_tls.c:2372 <= decrypt buf

I (24063) mbedtls: ssl_tls.c:4379 <= read record

I (24063) mbedtls: ssl_tls.c:8495 <= read

I (24073) HTTP_CLIENT: Redirect to https://raw.githubusercontent.com/lexus2k/nixie_clock/master/binaries/nixie_clock.txt
I (26913) mbedtls: ssl_tls.c:8021 => handshake

I (26913) mbedtls: ssl_cli.c:3405 client state: 0

I (26913) mbedtls: ssl_tls.c:2751 => flush output

I (26923) mbedtls: ssl_tls.c:2763 <= flush output

I (26923) mbedtls: ssl_cli.c:3405 client state: 1

I (26933) mbedtls: ssl_tls.c:2751 => flush output

I (26943) mbedtls: ssl_tls.c:2763 <= flush output

I (26943) mbedtls: ssl_cli.c:774 => write client hello

I (26953) mbedtls: ssl_tls.c:3180 => write handshake message

I (26963) mbedtls: ssl_tls.c:3337 => write record

I (26963) mbedtls: ssl_tls.c:2751 => flush output

I (26963) mbedtls: ssl_tls.c:2770 message length: 254, out_left: 254

I (26973) mbedtls: ssl_tls.c:2775 ssl->f_send() returned 254 (-0xffffff02)

I (26983) mbedtls: ssl_tls.c:2803 <= flush output

I (26993) mbedtls: ssl_tls.c:3470 <= write record

I (26993) mbedtls: ssl_tls.c:3314 <= write handshake message

I (27003) mbedtls: ssl_cli.c:1106 <= write client hello

I (27003) mbedtls: ssl_cli.c:3405 client state: 2

I (27013) mbedtls: ssl_tls.c:2751 => flush output

I (27013) mbedtls: ssl_tls.c:2763 <= flush output

I (27023) mbedtls: ssl_cli.c:1499 => parse server hello

I (27033) mbedtls: ssl_tls.c:4305 => read record

I (27033) mbedtls: ssl_tls.c:2532 => fetch input

I (27043) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (30903) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (30903) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (30913) mbedtls: ssl_tls.c:2738 <= fetch input

I (30913) mbedtls: ssl_tls.c:2532 => fetch input

I (30923) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 74

I (30933) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 74

I (30933) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 69 (-0xffffffbb)

I (30943) mbedtls: ssl_tls.c:2738 <= fetch input

I (30953) mbedtls: ssl_tls.c:4379 <= read record

I (30953) mbedtls: ssl_cli.c:1781 server hello, total extension length: 25

I (30963) mbedtls: ssl_cli.c:1970 <= parse server hello

I (30963) mbedtls: ssl_cli.c:3405 client state: 3

I (30973) mbedtls: ssl_tls.c:2751 => flush output

I (30983) mbedtls: ssl_tls.c:2763 <= flush output

I (30983) mbedtls: ssl_tls.c:5440 => parse certificate

I (30993) mbedtls: ssl_tls.c:4305 => read record

I (30993) mbedtls: ssl_tls.c:2532 => fetch input

I (31003) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (31003) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (31013) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (31023) mbedtls: ssl_tls.c:2738 <= fetch input

I (31023) mbedtls: ssl_tls.c:2532 => fetch input

I (31033) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 3187

I (31043) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 3187

I (31043) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 1353 (-0xfffffab7)

I (31413) EVENT: MIN HEAP: 119424, CURRENT HEAP: 133232
I (36053) mbedtls: ssl_tls.c:2717 in_left: 1358, nb_want: 3187

I (36053) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned -76 (-0x004c)

W (36053) mbedtls: ssl_tls.c:5019 mbedtls_ssl_fetch_input() returned -76 (-0x004c)

W (36063) mbedtls: ssl_tls.c:4338 ssl_get_next_record() returned -76 (-0x004c)

W (36073) mbedtls: ssl_tls.c:5480 mbedtls_ssl_read_record() returned -76 (-0x004c)

I (36073) mbedtls: ssl_tls.c:8031 <= handshake

E (36083) esp-tls: mbedtls_ssl_handshake returned -0x4c
E (36093) esp-tls: Failed to open new connection
E (36093) TRANS_SSL: Failed to open a new connection
E (36103) HTTP_CLIENT: Connection failed, sock < 0
E (36103) WEB: Failed to perform HTTP GET request from https://github.com/lexus2k/nixie_clock/raw/master/binaries/nixie_clock.txt

[jitin17]

@lexus2k I think somehow there seems to be a problem in reading the certificate received from https://raw.githubusercontent.com/lexus2k/nixie_clock/master/binaries/nixie_clock.txt

This is the part of the log where the problem appears.

I (30983) mbedtls: ssl_tls.c:5440 => parse certificate

I (30993) mbedtls: ssl_tls.c:4305 => read record

I (30993) mbedtls: ssl_tls.c:2532 => fetch input

I (31003) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (31003) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (31013) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (31023) mbedtls: ssl_tls.c:2738 <= fetch input

I (31023) mbedtls: ssl_tls.c:2532 => fetch input

I (31033) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 3187

I (31043) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 3187

I (31043) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 1353 (-0xfffffab7)

I (31413) EVENT: MIN HEAP: 119424, CURRENT HEAP: 133232

W (36053) mbedtls: ssl_tls.c:5019 mbedtls_ssl_fetch_input() returned -76 (-0x004c)

W (36063) mbedtls: ssl_tls.c:4338 ssl_get_next_record() returned -76 (-0x004c)

W (36073) mbedtls: ssl_tls.c:5480 mbedtls_ssl_read_record() returned -76 (-0x004c)

Somehow the entire 3187 bytes of certificate is not being read and -0x004c implies system error.

I (36053) mbedtls: ssl_tls.c:2717 in_left: 1358, nb_want: 3187

I (36053) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned -76 (-0x004c)

Since the problem is random, I think pcap capture would be of great help here.

On a side note, I tried to connect to the same URL with esp_http_client (ESP-IDF v3.2) and faced no issue. I see the entire 3187 bytes of the certificate being read on my device.

I (10883) mbedtls: ssl_tls.c:5440 => parse certificate

I (10893) mbedtls: ssl_tls.c:4305 => read record

I (10893) mbedtls: ssl_tls.c:2532 => fetch input

I (10903) mbedtls: ssl_tls.c:2693 in_left: 0, nb_want: 5

I (10913) mbedtls: ssl_tls.c:2717 in_left: 0, nb_want: 5

I (10913) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (10923) mbedtls: ssl_tls.c:2738 <= fetch input

D (10933) mbedtls: ssl_tls.c:4050 input record: msgtype = 22, version = [3:3], msglen = 3182

I (10933) mbedtls: ssl_tls.c:2532 => fetch input

I (10943) mbedtls: ssl_tls.c:2693 in_left: 5, nb_want: 3187

I (10953) mbedtls: ssl_tls.c:2717 in_left: 5, nb_want: 3187

I (10953) mbedtls: ssl_tls.c:2718 ssl->f_recv(_timeout)() returned 3182 (-0xfffff392)

I (10963) mbedtls: ssl_tls.c:2738 <= fetch input

D (10993) mbedtls: ssl_tls.c:3620 handshake message: msglen = 3182, type = 11, hslen = 3182

I (10993) mbedtls: ssl_tls.c:4379 <= read record

[lexus2k]

@jitin17 Thank you for clarifications. I understand that the problem relates to network issue. And what I have for now:

1. ESP32 experiences TLS issues at my home network
2. ESP32 has no issues with TLS at the office network
3. Other home devices have no issues with SSL connection to github site.

Thus, I came to conclusion, that ESP32 has some specific code in TLS implementation, which is sensitive to network environment. How can I get PCAP logs? ASUS RT-66 doesn't allow to get such logs, and the router is the only device at my place between ESP32 and github server. Of course, I can try to direct TCP traffic from ESP32 via hotspot on the laptop, but that will be different case.

[jitin17]

@lexus2k You can get PCAP logs with the help of Wireshark, TCPDump etc.

[lexus2k]

@jitin17 Hi, I know about Wireshark and TCPDump, but as I said above, to capture TCP traffic the only place to run these tools is WiFi router, and my router doesn't allow to run these tools. Anyway, I tried to reproduce issue again several times, and everything works OK for now. I did no changes to esp32 firmware, maybe the issue was caused by network provider. I will keep an eye on TLS behavior, and will report as soon as I meet the problem again.

[jitin17]

@lexus2k Glad to know it got fixed.

@AadiMehta I am closing this issue, please feel free to reopen it if you still face a similar problem.

[ankitdaf]

@jitin17

We are facing the same problem. A small snippet of the log is here :

E (4396500) esp-tls: mbedtls_ssl_handshake returned -0x4c E (4396500) esp-tls: Failed to open new connection E (4396500) TRANS_SSL: Failed to open a new connection E (4396500) HTTP_CLIENT: Connection failed, sock < 0 E (4396510) HTTP_CLIENT: HTTP GET request failed: ESP_ERR_HTTP_CONNECT

[cheezum]

Same problem here (-0x4c) after updating. I'm running on 4.0-dev-1443 with CMake as compiler. I tried to enable the debugging, but that gives a lot of errors on the OTA partition and partitions not being bootable.

[mahavirj]

@ankitdaf @cheezum We have fix for this regression, it will reflect on github repository soon. Until then please try attached fix, mbedtls_fix_errno_handling.tar.gz

[cheezum]

Thanks. This patch works for me !!

[Bertoleti]

I have the same issue. I'm using IDF 4.13 on Eclipse. How can I install this patch with corrections?

E (12819080) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x4c E (12819080) esp-tls: Failed to open new connection E (12819090) TRANS_SSL: Failed to open a new connection I (12819090) wifi station: retry to connect to the AP E (12819090) HTTP_CLIENT: Connection failed, sock < 0 I (12819100) wifi station: connect to the AP fail I (12819100) http events: HTTP_EVENT_DISCONNECTED I (12821680) tcpip_adapter: sta ip: 10.211.6.189, mask: 255.255.248.0, gw: 10.211.0.1 I (12821680) wifi station: got ip:10.211.6.189

[MohdAzka]

Hi I was working on esp-idf example code 'simple_ota_example' and i was getting the same error like that "Failed to open new connection"

E (3893) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x7200 I (3893) esp-tls-mbedtls: Certificate verified. E (3893) esp-tls: Failed to open new connection E (3903) TRANS_SSL: Failed to open a new connection E (3913) HTTP_CLIENT: Connection failed, sock < 0 E (3913) esp_https_ota: Failed to open HTTP connection: ESP_ERR_HTTP_CONNECT E (3923) esp_https_ota: Failed to establish HTTP connection E (3923) simple_ota_example: Firmware upgrade failed

until i have change my url from "https://192.168.1.141/..." to "http://192.168.1.141/..."

now everything is working fine

[lexus2k]

Hi @MohdAzka

Everything is find for me now, I don't observe the issue, since I switched to newer IDF releases. Both v4.0.1 and v3.3 are good for me.