Crash from btdm controller task & esp_task_wdt_reset(783): task not found (IDFGH-12335)

AnikChen commented 7 months ago

Answers checklist.

[X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
[X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
[X] I have searched the issue tracker for a similar issue and not found a similar issue. (PS: Indeed there are variously similar issues but not the same as mine.)

IDF version.

v5.0.6

Espressif SoC revision.

ESP32S3

Operating System used.

Windows

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-S3-WROOM-1

Power Supply used.

External 5V

What is the expected behavior?

No exception.

What is the actual behavior?

There's an exception that caused reboot.

Steps to reproduce.

It seems random, but I can provide some information about my platform:

1> WiFi-sta & BLE-peripheral co-exist on CPU1. 2> RGB-LCD module with a touchpad. 3> LVGL GUI, and the task of the LVGL on CPU0 is: void lv_tick_task(void *arg)
{ xGuiSemaphore = xSemaphoreCreateMutex();

while (1) {
    vTaskDelay((20) / portTICK_PERIOD_MS); 
    if (pdTRUE == xSemaphoreTake(xGuiSemaphore, portMAX_DELAY)) {
        lv_task_handler();
        xSemaphoreGive(xGuiSemaphore);
    }
}

} 4> Some pages and buttons generated by LVGL. 5> Sometimes, after flashed ESP32S3, touched a GUI button to switch the pages, the exception was threw out. 6> According to the backtrace, it's easy to locate the exceptional point (in xQueueSemaphoreTake()): configASSERT( !( ( xTaskGetSchedulerState() == taskSCHEDULER_SUSPENDED ) && ( xTicksToWait != 0 ) ) ); 7> The exception also showed "esp_task_wdt_reset(783): task not found" but no esp_task_wdt_xxx() used. 8> The exception occurred both on IDF-V5.0.5 and IDF-V5.0.6. I have not encountered it when originally used IDF-V5.0.1.

Debug Logs.

Encountered 3 times until now. Here are 2 logs of them:

[First]:
E (13889) task_wdt: esp_task_wdt_reset(783): task not found
E (13889) task_wdt: Aborting.
t (13889) task_wdt: Prin; 1mU 11backt tcesk_w

Backtrace: 0x40386c77:0x3fccc960 0x42065969:0x3fccc9a0 0x4038042d:0x3fccc9c0
0x40386c77: xQueueSemaphoreTake at C:/Espressif/frameworks/esp-idf-v5.0.6/components/freertos/FreeRTOS-Kernel/queue.c:1561 (discriminator 2)

0x42065969: semphr_take_wrapper at C:/Espressif/frameworks/esp-idf-v5.0.6/components/bt/controller/esp32c3/bt.c:567
 (inlined by) semphr_take_wrapper at C:/Espressif/frameworks/esp-idf-v5.0.6/components/bt/controller/esp32c3/bt.c:564

0x4038042d: btdm_controller_task at ??:?

[Second]:
E (1067879) task_wdt: esp_task_wdt_reset(783): task not found
E (1067879) task_wdt: Aborting.
E (1067879) task_dt;3PriEt(10U717b)ckarkcwdt: A

Backtrace: 0x40386c77:0x3fccc8b0 0x42065725:0x3fccc8f0 0x4038042d:0x3fccc910
0x40386c77: xQueueSemaphoreTake at C:/Espressif/frameworks/esp-idf-v5.0.6/components/freertos/FreeRTOS-Kernel/queue.c:1561 (discriminator 2)

0x42065725: semphr_take_wrapper at C:/Espressif/frameworks/esp-idf-v5.0.6/components/bt/controller/esp32c3/bt.c:567
 (inlined by) semphr_take_wrapper at C:/Espressif/frameworks/esp-idf-v5.0.6/components/bt/controller/esp32c3/bt.c:564

0x4038042d: btdm_controller_task at ??:?

More Information.

Here are some informations from the debug-print of reboot:

ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0x28 (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fce3810,len:0x1858 load:0x403c9700,len:0xd90 load:0x403cc700,len:0x2f54 entry 0x403c9930 I (24) boot: ESP-IDF v5.0.6-dirty 2nd stage bootloader I (25) boot: compile time 08:23:55 I (25) boot: Multicore bootloader I (27) boot: chip revision: v0.1 I (31) qio_mode: Enabling default flash chip QIO
I (36) boot.esp32s3: Boot SPI Speed : 80MHz I (41) boot.esp32s3: SPI Mode : QIO I (46) boot.esp32s3: SPI Flash Size : 16MB I (51) boot: Enabling RNG early entropy source...

I (895) boot: Loaded app from partition at offset 0x100000 I (895) boot: Disabling RNG early entropy source... I (907) cpu_start: Multicore app I (907) octal_psram: vendor id : 0x0d (AP) I (908) octal_psram: dev id : 0x02 (generation 3) I (911) octal_psram: density : 0x03 (64 Mbit) I (916) octal_psram: good-die : 0x01 (Pass) I (921) octal_psram: Latency : 0x01 (Fixed) I (927) octal_psram: VCC : 0x01 (3V) I (932) octal_psram: SRF : 0x01 (Fast Refresh) I (937) octal_psram: BurstType : 0x01 (Hybrid Wrap) I (943) octal_psram: BurstLen : 0x01 (32 Byte) I (949) octal_psram: Readlatency : 0x02 (10 cycles@Fixed) I (955) octal_psram: DriveStrength: 0x00 (1/1) I (961) MSPI Timing: PSRAM timing tuning index: 5 I (965) esp_psram: Found 8MB PSRAM device I (970) esp_psram: Speed: 80MHz I (1052) mmu_psram: Instructions copied and mapped to SPIRAM I (1255) mmu_psram: Read only data copied and mapped to SPIRAM I (1255) cpu_start: Pro cpu up. I (1255) cpu_start: Starting app cpu, entry point is 0x40379854 0x40379854: call_start_cpu1 at C:/Espressif/frameworks/esp-idf-v5.0.6/components/esp_system/port/cpu_start.c:147

I (0) cpu_start: App cpu up. I (1386) esp_psram: SPI SRAM memory test OK I (1394) cpu_start: Pro cpu start user code I (1394) cpu_start: cpu freq: 240000000 Hz I (1394) cpu_start: Application information: I (1398) cpu_start: Project name: lvgl_demo I (1403) cpu_start: App version: v1.0.1_https_ota-194-ged6c9b4-d I (1410) cpu_start: Compile time: Mar 9 2024 08:23:26 I (1416) cpu_start: ELF file SHA256: ee0e91f67231e3c3... I (1422) cpu_start: ESP-IDF: v5.0.6-dirty I (1428) cpu_start: Min chip rev: v0.0 I (1432) cpu_start: Max chip rev: v0.99 I (1437) cpu_start: Chip rev: v0.1 I (1442) heap_init: Initializing. RAM available for dynamic allocation: I (1449) heap_init: At 3FCB27A0 len 00036F70 (219 KiB): DRAM I (1456) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM I (1463) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM I (1469) esp_psram: Adding pool of 3584K of PSRAM memory to heap allocator I (1477) spi_flash: detected chip: gd I (1481) spi_flash: flash io: qio I (1485) sleep: Configure to isolate all GPIO pins in sleep state I (1492) sleep: Enable automatic switching of GPIO sleep configuration I (1499) coexist: coexist rom version e7ae62f I (1504) app_start: Starting scheduler on CPU0 I (1509) app_start: Starting scheduler on CPU1 I (1509) main_task: Started on CPU0 I (1519) esp_psram: Reserving pool of 8K of internal memory for DMA/internal allocations I (1529) main_task: Calling app_main()

I sinceresly appreciate for your help.

0xjakob commented 6 months ago

@AnikChen It is hard to say what is wrong here due the number of things that can go wrong. The configASSERT just tells us what exactly is wrong in the FreeRTOS code at run time. But we don't know why. To further nail down the problem, probably the first option would be enabling debugging options, such as Heap poisoning and enabling the watchpoint at the end of the stack (Menuconfig → Component config → FreeRTOS → Port). Since the task watchdog is complaining about a missing task, you could also register a task pre-deletion hook, after enabling it by Menuconfig → Component config → FreeRTOS → Port, to see which tasks are deleted. It would also be good to remove parts of the application to see what actually triggers the issue. Ideally, there would be a minimal reproducing example which we can analyze.

AnikChen commented 6 months ago

@0xjakob Thanks for your kind response and good advices. It's not easy to reproduce the exception but I'll try with your methods. If there is any discovery, I'll let you know. Thank you!

AnikChen commented 5 months ago

@0xjakob Thanks for your kind response and good advices. It's not easy to reproduce the exception but I'll try with your methods. If there is any discovery, I'll let you know. Thank you! @0xjakob Found it! It's that an overflow occurred in writing an array. Sorry to bother you guys.

espressif / esp-idf