[esp-idf v5.1.2 ] SW_CPU_RESET happening when internet disconnects

[Suresh]

Hi,

Build environment:

SDK: ESP-IDF v5.1.2
Device: ESP32
Component: OTA

Issue #: Reproducing steps:

During the OTA update (bin downloading time) disconnecting the internet (do not turn off router) MQTT crash is observed , because of application is trying to publishing the fail status. Please check the logs below.

I (122581) [ota]: Downloaded 63488 bytes.
I (122581) [ota]: Downloaded 64512 bytes.
I (122581) [ota]: Downloaded 65536 bytes.
E (127591) transport_base: esp_tls_conn_read error, errno=No more processes
W (127591) HTTP_CLIENT: esp_transport_read returned:0 and errno:11
I (127591) [ota]: Downloaded 65928 bytes.
I (132611) [ota]: Downloaded 65928 bytes.
I (137621) [ota]: Downloaded 65928 bytes.
E (142321) transport_base: poll_read select error 113, errno = Software caused connection abort, fd = 55
E (142321) HTTP_CLIENT: transport_read: error - 57347 | ERROR
E (142321) [ota]: HTTP_EVENT_ERROR
E (142331) esp_https_ota: data read -1, errno 0
I (142331) [ota]: Downloaded 65928 bytes.
I (142341) esp_image: segment 0: paddr=00190020 vaddr=3f400020 size=2a424h (173092) map
E (142401) esp_image: invalid segment length 0xffffffff
E (142401) [ota]: HTTP_EVENT_DISCONNECTED
E (142401) [ota]: HTTP_EVENT_DISCONNECTED
E (142471) esp-tls: Failed to open new connection
E (142481) transport_base: Failed to open a new connection
E (142481) mqtt_client: Error transport connect
E (142491) [cloud_mode]: ERROR Code: 0
I (142501) [cloud_mode]: [MqttEventHandler] Memory Gained: 0 bytes
E (142511) [cloud_mode]: DISCONNECTED
E (142521) [cloud_mode]: MemoGuru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.

Core 1 register dump:
PC : 0x400f03e7 PS : 0x00060a30 A0 : 0x800eec8e A1 : 0x3ffdc5c0
0x400f03e7: outbox_enqueue at /home/nagasuresh/esp-idf-v5.1.2/components/mqtt/esp-mqtt/lib/mqtt_outbox.c:61

A2 : 0x3ffe38e0 A3 : 0x00000000 A4 : 0x3ffeb320 A5 : 0x00000000
A6 : 0x3ffe38c4 A7 : 0x00000000 A8 : 0x800f03ce A9 : 0x3ffdc5b0
A10 : 0x3ffeb320 A11 : 0x00000000 A12 : 0x00000063 A13 : 0x3ffeb382
A14 : 0x0000007d A15 : 0x0000007d SAR : 0x00000018 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000004 LBEG : 0x4000c349 LEND : 0x4000c36b LCOUNT : 0x00000000
0x4000c349: memcpy in ROM

0x4000c36b: memcpy in ROM



Backtrace: 0x400f03e4:0x3ffdc5c0 0x400eec8b:0x3ffdc5f0 0x400eed26:0x3ffdc630 0x400efaf6:0x3ffdc650 0x400e11e3:0x3ffdc690 0x400dc259:0x3ffdc710 0x400dc289:0x3ffdc7a0 0x400dc35b:0x3ffdc7c0 0x40096bb9:0x3ffdc7e0
0x400f03e4: outbox_enqueue at /home/nagasuresh/esp-idf-v5.1.2/components/mqtt/esp-mqtt/lib/mqtt_outbox.c:61

0x400eec8b: mqtt_enqueue at /home/nagasuresh/esp-idf-v5.1.2/components/mqtt/esp-mqtt/mqtt_client.c:1171

0x400eed26: mqtt_client_enqueue_publish at /home/nagasuresh/esp-idf-v5.1.2/components/mqtt/esp-mqtt/mqtt_client.c:2002

0x400efaf6: esp_mqtt_client_publish at /home/nagasuresh/esp-idf-v5.1.2/components/mqtt/esp-mqtt/mqtt_client.c:2057

To avoid the above issue, enabled "MQTT_SKIP_PUBLISH_IF_DISCONNECTED" macro
Now device crash is not observed,instead device SW_CPU_RESET is happening, please check the below logs for reference.

I (86521) [ota]: Downloaded 63488 bytes.
I (86521) [ota]: Downloaded 64512 bytes.
I (86531) [ota]: Downloaded 65536 bytes.
I (86531) wifi:state: run -> init (0)
I (86531) wifi:pm stop, total sleep time: 19306993 us / 35211451 us

I (86541) wifi:<ba-del>idx:0, tid:0
I (86541) wifi:<ba-del>idx:1, tid:6
I (86551) wifi<1,0>, old:<1,1>, ap:<255,255>, sta:<1,1>, prof:1
E (86551) wifi:NAN WiFi stop
W (86551) [wifi]: *** WiFi Disconnected ***
W (86571) [wifi]: Retrying connection

E (86581) [wifi]: Reconnect Failed. Reason: 12290
I (86601) [cloud_mode]: Can NOT connect to the Azure IoTHub now.
W (86601) [local_mode]: recv() failed errno:113
W (86611) [local_mode]: Could not shutdown: 56 (128)
E (86631) [cloud_mode]: [_connectivity_handler] Memory Lost: 4294966876 bytes
I (86651) [local_mode]: Disconnected. Closing TCP Socket Server
E (86601) esp-tls-mbedtls: read error :-0x004C:
E (86661) transport_base: esp_tls_conn_read error, errno=Software caused connection abort
E (86661) [local_mode]: [ConnectivityHandler] Memory Lost: 4294967268 bytes
W (86671) HTTP_CLIENT: esp_transport_read returned:-76 and errno:113
I (86691) wifi:flush txqE (86691) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL

I (86701) wifi:stop sw txq
I (86701) [ota]: Downloaded 65928 bytes.
I (86701) wifi:lmac stop hw txq
E (86711) transport_base: poll_read select error 113,ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:5820
ho 0 tail 12 room 4
load:0x40078000,len:15104
load:0x40080400,len:4
0x40080400: _init at ??:?

load:0x40080404,len:3500
entry 0x400805e4
I (599) cpu_start: Multicore app
I (599) cpu_start: Pro cpu up.
I (599) cpu_start: Starting app cpu, entry point is 0x400816a0
0x400816a0: call_start_cpu1 at /home/nagasuresh/esp-idf-v5.1.2/components/esp_system/port/cpu_start.c:157

I (586) cpu_start: App cpu up.
I (617) cpu_start: Pro cpu start user code
I (617) cpu_start: cpu freq: 240000000 Hz
I (648) cpu_start: ESP-IDF: v5.1.2
I (653) cpu_start: Min chip rev: v0.0
I (657) cpu_start: Max chip rev: v3.99
I (662) cpu_start: Chip rev: v3.0

Please note that, This kind of behaviour observed multiple places mostly while MQTT publish time.

is this expected behaviour or some issue? please help me out resolving this issue.


Regards,
Suresh