Error -76 from MbedTLS (IDFGH-3650) (CA-77)
Opened this issue · 11 comments
Environment
- Development Kit: ESP32-DevKitC
- Kit version (for WroverKit/PicoKit/DevKitC): v1
- Module or chip used: ESP32-WROOM-32
- IDF version (run
git describe --tagsto find it):
v4.2-dev-1303-gcd4fa46f5 - Build System: idf.py
- Compiler version (run
xtensa-esp32-elf-gcc --versionto find it):
xtensa-esp32-elf-gcc (crosstool-NG esp-2020r1) 8.2.0 - Operating System: macOS
- Using an IDE?: VSCode
- Power Supply: USB
Problem Description
Running esp-azure and sending telemetry data. After a time im getting following error on each send:
Error: Time:Tue Jul 14 10:04:30 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_send_async Line:552 tlsio_esp_tls_send_async without a prior successful open
Error: Time:Tue Jul 14 10:04:30 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:395 Failure sending control packet data
Error: Time:Tue Jul 14 10:04:30 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:mqtt_client_publish Line:1101 Error: mqtt_client_publish send failed
Error: Time:Tue Jul 14 10:04:30 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:publish_mqtt_telemetry_msg Line:898 Failed attempting to publish mqtt message
After this happened a few times following error is printed:
Error: Time:Tue Jul 14 10:04:44 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_destroy Line:153 tlsio_esp_tls_destroy called while not in TLSIO_STATE_CLOSED.
I (2889204) azure_client:
Connection Status result:IOTHUB_CLIENT_CONNECTION_UNAUTHENTICATED, Connection Status reason: IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN
Guru Meditation Error: Core 0 panic'ed (IllegalInstruction). Exception was unhandled.
Core 0 register dump:
PC : 0x6572757a PS : 0x00060630 A0 : 0x800e48ae A1 : 0x3ffd90b0
A2 : 0x3ffd7944 A3 : 0x00000000 A4 : 0x3ffd7974 A5 : 0x40a68000
A6 : 0x7ff00000 A7 : 0x00000200 A8 : 0x801a0f92 A9 : 0x3ffd9080
A10 : 0x3ffd77ac A11 : 0x00000000 A12 : 0x3f40342c A13 : 0x002c15f4
A14 : 0x3f40b1cc A15 : 0x7ff5fb1c SAR : 0x00000004 EXCCAUSE: 0x00000000
EXCVADDR: 0x00000000 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xfffffff5
Backtrace:0x65727577:0x3ffd90b0 |<-CORRUPTED
Im using the light sleep mode, if this could be helpful.
Expected Behavior
No errors.
Thanks for reporting, we will look into.
Thanks!
To me it really seems that it is connected to the light sleep.
Is it possible that my tasks which uses the esp-azure to send telemetry data have to be delayed after sleep, so the wifi can connect?
Is there a possibility to wait for wifi after awake of light sleep?
Update: This also occurs on the current stable release (4.0.1). ESP-IDF current master branch.
@schroedermarius , have you tried without the light sleep? Does the issue not occur then?
@shahpiyushv
Thanks for your reply.
The error only occurs with light sleep short time before im getting IOTHUB_CLIENT_CONNECTION_EXPIRED_SAS_TOKEN.
@shahpiyushv Seems I was wrong. Im Sorry. After a long time, this also happens without Light Sleep.
We changed SAS Authentication to Device certificates, which does not help. At any point it cant publish the messages:
Error: Time:Wed Aug 5 06:30:36 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_send_async Line:552 tlsio_esp_tls_send_async without a prior successful open
Error: Time:Wed Aug 5 06:30:36 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:395 Failure sending control packet data
Error: Time:Wed Aug 5 06:30:36 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:mqtt_client_publish Line:1101 Error: mqtt_client_publish send failed
Error: Time:Wed Aug 5 06:30:36 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/iothub_client/src/iothubtransport_mqtt_common.c Func:publish_mqtt_telemetry_msg Line:898 Failed attempting to publish mqtt message
@schroedermarius , can you tell me how much is "a long time"? That will help me understand how long I need to keep my setup running to reproduce this.
@shahpiyushv Did it over the night. So can't tell an exact time. It was a maximum of 20 hours.
At another place I read about someone who had an equivalent error which was the result of a memory leak.
Currently im monitoring the memory.
In my application it started with
I (2070561) azure_client: Free heap size: 93284
I (2070561) azure_client: Min free heap size: 76248
after 400 messages I've got following:
I (2070561) azure_client: Free heap size: 91424
I (2070561) azure_client: Min free heap size: 73960
Could this already be a problem?
I've also started the demo application "iothub_client_sample_mqtt" with smaller modifications, so it does not stop after 50 messages. There i got the following values:
I (2070561) azure_client: Free heap size: 173352
I (2070561) azure_client: Min free heap size: 159508
after about 400 messages
I (2070561) azure_client: Free heap size: 173180
I (2070561) azure_client: Min free heap: 159508
@shahpiyushv
I've also discovered another thing:
When im disabeling the device in azure portal, the ESP does never log IOTHUB_CLIENT_CONNECTION_DEVICE_DISABLED... It just loses the connection, which seems to be wrong. I also cant figure out any "Retry" call to establish the connection again.
@schroedermarius , memory does not seem to be a problem in your case as there is quite some free memory available at all times (as per Min free heap size).
Regarding the other point, the examples are actually directly taken from azure-iot-sdk-c and most logic in it is by Azure. We just have the logic for connecting to the Wi-Fi network and an abstraction layer for TLS. I will indeed check if the original issue is in the TLS layer, but this new issue about not getting IOTHUB_CLIENT_CONNECTION_DEVICE_DISABLED could be something in the azure sdk itself.
Hi @shahpiyushv
first of all, thank you for your help! I really appreciate that.
As for now it seems like I need to have Keep-Alive calls to realize the IOTHUB_CLIENT_CONNECTION_DEVICE_DISABLED state. For thus, the keep alive interval has to be lower than my iteration for messaging.
I'm sending messages every 5 seconds. So my keep alive interval is 1 second for now.
As I said, we are using the light sleep mode. There seem to be some problems with keep alive regarding light sleep.
After the ESP32 awake from light sleep, he trys to send immediately a Keep Alive (PINGREQ), but sometimes this fails with the follwing error:
E (383043) esp-tls: read error :-76:
Error: Time:Thu Aug 6 12:03:11 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_send_async Line:552 tlsio_esp_tls_send_async without a prior successful open
Error: Time:Thu Aug 6 12:03:11 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:395 Failure sending control packet data
-> 12:03:11 PINGREQ
Error: Time:Thu Aug 6 12:03:12 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_send_async Line:552 tlsio_esp_tls_send_async without a prior successful open
Error: Time:Thu Aug 6 12:03:12 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:395 Failure sending control packet data
-> 12:03:12 PINGREQ
Error: Time:Thu Aug 6 12:03:13 2020 File:/Users/marius/esp/esp-azure/port/src/tlsio_esp_tls.c Func:tlsio_esp_tls_send_async Line:552 tlsio_esp_tls_send_async without a prior successful open
Error: Time:Thu Aug 6 12:03:13 2020 File:/Users/marius/esp/esp-azure/azure-iot-sdk-c/umqtt/src/mqtt_client.c Func:sendPacketItem Line:395 Failure sending control packet data
-> 12:03:13 PINGREQ
Do you have some informations, what I could try?
Sleep Mode is executed in main thread, sending in another thread (which should be paused automatically by sleep mode, right?).