Running mqtt on ESP32_ID4 cause "E (506885) task_wdt: Task watchdog got triggered."

[MaBecker]

Find on ESP32_IDF4 build, It does not happen for ESP32 builds - It happens sporadicly . Can anyone else please check this or try this for a ESPC3_IDF4 or ESP32S6_IDF4 board.

version info

process.env
={
  VERSION: "2v25.13",
  GIT_COMMIT: "1d58afe3a",
  BOARD: "ESP32_IDF4",
  RAM: 524288, FLASH: 0, STORAGE: 262144,
  SERIAL: "e05a1b23-0668",
  CONSOLE: "Serial1",
  MODULES: "Flash,Storage,hea" ... "kJS,Wifi,neopixel",
  EXPTR: 1061230332 }

Striped down sample coding

var wifi=require("Wifi");
var ssid="your ssid";
var password="your ssid password";

wifi.disconnect(() => {
  wifi.connect(ssid, {password: password}, function(e) {
    if (e === null ) {
      print("wifi: connected");
      print("mqtt: connect to broker");
      mqtt = require("MQTT").connect({host: "test.mosquitto.org"});
      mqtt.on('connected', function() {
        print("mqtt: connected");
      });
    } else {
      print("wifi: connect error:",e);
    }
  });
});

output

>;31mE (436245) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:m
;31mE (436245) task_wdt:  - IDLE0 (CPU 0)m
;31mE (436245) task_wdt: Tasks currently running:m
;31mE (436245) task_wdt: CPU 0: espruinoTaskm
;31mE (436245) task_wdt: CPU 1: IDLE1m
;31mE (436245) task_wdt: Print CPU 0 (current core) backtracem
Backtrace: 0x401639FE:0x3FFBE920 0x400833ED:0x3FFBE940 0x4000BFED:0x3FFD9460 0x400951A6:0x3FFD9470 0x40092A95:0x3FFD9490 0x400836BA:0x3FFD94D0 0x4008376D:0x3FFD9500 0x400D5073:0x3FFD9520 0x400F7761:0x3FFD9590 0x401DCE6B:0x3FFD95E0 0x401152FB:0x3FFD9600 0x40115D8D:0x3FFD9870 0x4010A7E4:0x3FFD98B0 0x400F088F:0x3FFD9910 0x400F458A:0x3FFD9930 0x400F4795:0x3FFD99F0 0x400D81B6:0x3FFD9A10
;31mE (436245) task_wdt: Print CPU 1 backtracem
Backtrace: 0x40086F95:0x3FFBEF20 0x400833ED:0x3FFBEF40 0x4000BFED:0x3FFBC7E0 0x400951A6:0x3FFBC7F0 0x40163C6F:0x3FFBC810 0x40163C7B:0x3FFBC840 0x400D418E:0x3FFBC860 0x400933B4:0x3FFBC880

backtrace info CPU 0

0x401639fe: task_wdt_isr at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/esp_system/task_wdt.c:183
0x400951a6: vPortClearInterruptMaskFromISR at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/port/xtensa/include/freertos/portmacro.h:571
0x400951a6: vPortExitCritical at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/port/xtensa/port.c:332
0x40092a95: xQueueGenericSend at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/queue.c:946
0x400836ba: lock_release_generic at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/newlib/locks.c:201
0x4008376d: _lock_release at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/newlib/locks.c:207
0x400d5073: esp_vfs_select at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/vfs/vfs.c:918
0x400f7761: net_esp32_recv at /Users/markbecker/Documents/github/Espruino/Espruino/libs/network/esp32/network_esp32.c:251
0x401dce6b: netRecv at /Users/markbecker/Documents/github/Espruino/Espruino/libs/network/network.c:722
0x401152fb: socketClientConnectionsIdle at /Users/markbecker/Documents/github/Espruino/Espruino/libs/network/socketserver.c:676
0x40115d8d: socketIdle at /Users/markbecker/Documents/github/Espruino/Espruino/libs/network/socketserver.c:834
0x4010a7e4: jswrap_net_idle at /Users/markbecker/Documents/github/Espruino/Espruino/libs/network/jswrap_net.c:31
0x400f088f: jswIdle at /Users/markbecker/Documents/github/Espruino/Espruino/gen/jswrapper.c:1907
0x400f458a: jsiIdle at /Users/markbecker/Documents/github/Espruino/Espruino/src/jsinteractive.c:2537
0x400f4795: jsiLoop at /Users/markbecker/Documents/github/Espruino/Espruino/src/jsinteractive.c:2640
0x400d81b6: espruinoTask at /Users/markbecker/Documents/github/Espruino/Espruino/targets/esp32/main.c:108

backtrace info CPU 1

0x40086f95: esp_crosscore_isr at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/esp_system/crosscore_int.c:92
0x400951a6: vPortClearInterruptMaskFromISR at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/port/xtensa/include/freertos/portmacro.h:571
0x400951a6: vPortExitCritical at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/port/xtensa/port.c:332
0x40163c6f: esp_task_wdt_reset at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/esp_system/task_wdt.c:334
0x40163c7b: idle_hook_cb at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/esp_system/task_wdt.c:80
0x400d418e: esp_vApplicationIdleHook at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/esp_system/freertos_hooks.c:51
0x400933b4: prvIdleTask at /Users/markbecker/Documents/github/Espruino/Espruino/esp-idf-4/esp-idf/components/freertos/tasks.c:4099

[MaBecker]

It does not happen when using tinyMQTT.

sample coding

wifi.disconnect(() => {
  wifi.connect(ssid, {password: password}, function(e) {
    if (e === null ) {
      print("wifi: connected");
      print("mqtt: connect to broker");
      mqtt = require("tinyMQTT").create("test.mosquitto.org");
      mqtt.connect();    // was missing
      mqtt.on('connected', function() {
        print("mqtt: connected");
      });
    } else {
      print("wifi: connect error:",e);
    }
  });
});

Same behavior with tinyMQTT

[MaBecker]

@gfwilliams Any clue what is causing this?

[gfwilliams]

Not exactly, no...

But the way networking usually works in Espruino, the esp_vfs_select function in the stack trace (eg https://github.com/espruino/Espruino/blob/master/libs/network/esp32/network_esp32.c#L251) should complete immediately and return whether there's any data available on the channels its called on - that's why it's called with a timeout set to 0.

If the WDT fails, presumably it's blocking in that function which it shouldn't? It might be worth adding some print statements to check if it is blocking or if it's just chance the backtrace included it.

But actually I think in other builds like C3 we might try and disable task_wdt causing a reboot so maybe it's a sdkconfig issue? Even if that's the case we should probably fix the select call if it is blocking because that'll be screwing up other execution

[MaBecker]

Just set ESP_TASK_WDT_CHECK_IDLE_TASK_CPU0(=n) "Watch CPU0 Idle Task" and extendet the tinyMQTT to receive messages and is works. But I guess this is just a work around.