Intermitent crash during IDF initialisation (IDFGH-9240)

[KaeLL]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

9ee3c83

Operating System used.

Linux

How did you build your project?

Command line with idf.py

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

None

Development Kit.

Custom Board

Power Supply used.

External 5V

What is the expected behavior?

To not crash, especially before getting to my code.

What is the actual behavior?

Intermitenttly crashing here.

Steps to reproduce.

defconfig

CONFIG_BOOTLOADER_COMPILER_OPTIMIZATION_PERF=y
CONFIG_BOOTLOADER_LOG_LEVEL_NONE=y
CONFIG_BOOTLOADER_APP_ROLLBACK_ENABLE=y
CONFIG_BOOTLOADER_SKIP_VALIDATE_ALWAYS=y
CONFIG_ESPTOOLPY_FLASHMODE_QIO=y
CONFIG_ESPTOOLPY_FLASHFREQ_80M=y
CONFIG_ESPTOOLPY_FLASHSIZE_4MB=y
# CONFIG_ESPTOOLPY_FLASHSIZE_DETECT is not set
CONFIG_ESPTOOLPY_AFTER_NORESET=y
CONFIG_ESPTOOLPY_MONITOR_BAUD_CONSOLE=y
CONFIG_PARTITION_TABLE_CUSTOM=y
CONFIG_PARTITION_TABLE_CUSTOM_FILENAME="partitions_ota.csv"
CONFIG_PARTITION_TABLE_OFFSET=0xC000
CONFIG_COMPILER_WARN_WRITE_STRINGS=y
CONFIG_BT_ENABLED=y
CONFIG_BTDM_CTRL_BLE_MAX_CONN=1
# CONFIG_BTDM_CTRL_MODEM_SLEEP is not set
# CONFIG_BTDM_BLE_SCAN_DUPL is not set
# CONFIG_BTDM_BLE_ADV_REPORT_FLOW_CTRL_SUPP is not set
# CONFIG_BT_BLE_SMP_ENABLE is not set
CONFIG_BT_STACK_NO_LOG=y
CONFIG_BT_ACL_CONNECTIONS=1
# CONFIG_BT_MULTI_CONNECTION_ENBALE is not set
CONFIG_BT_BLE_DYNAMIC_ENV_MEMORY=y
CONFIG_BT_BLE_HOST_QUEUE_CONG_CHECK=y
CONFIG_SPI_MASTER_IN_IRAM=y
# CONFIG_SPI_SLAVE_ISR_IN_IRAM is not set
CONFIG_ESP_TLS_INSECURE=y
CONFIG_ESP_TLS_SKIP_SERVER_CERT_VERIFY=y
CONFIG_ESP32_REV_MIN_1=y
CONFIG_ESP32_DEFAULT_CPU_FREQ_240=y
CONFIG_ESP32_ULP_COPROC_ENABLED=y
CONFIG_ESP32_ULP_COPROC_RESERVE_MEM=128
# CONFIG_ESP32_DEBUG_OCDAWARE is not set
CONFIG_ESP32_RTC_CLK_SRC_INT_8MD256=y
CONFIG_ETH_DMA_BUFFER_SIZE=256
CONFIG_ETH_DMA_RX_BUFFER_NUM=3
CONFIG_ETH_DMA_TX_BUFFER_NUM=3
# CONFIG_ETH_USE_SPI_ETHERNET is not set
# CONFIG_ESP_EVENT_POST_FROM_ISR is not set
CONFIG_ESP_HTTP_CLIENT_ENABLE_BASIC_AUTH=y
# CONFIG_ESP_HTTP_CLIENT_ENABLE_DIGEST_AUTH is not set
# CONFIG_ESP_PHY_CALIBRATION_AND_DATA_STORAGE is not set
CONFIG_ESP_SYSTEM_PANIC_PRINT_HALT=y
CONFIG_ESP_MAIN_TASK_STACK_SIZE=10240
CONFIG_ESP_CONSOLE_UART_CUSTOM=y
CONFIG_ESP_CONSOLE_UART_BAUDRATE=921600
CONFIG_ESP_INT_WDT_TIMEOUT_MS=30
CONFIG_ESP_TASK_WDT_PANIC=y
# CONFIG_ESP32_WIFI_NVS_ENABLED is not set
# CONFIG_ESP32_WIFI_IRAM_OPT is not set
CONFIG_ESP_COREDUMP_ENABLE_TO_UART=y
CONFIG_ESP_COREDUMP_MAX_TASKS_NUM=30
CONFIG_FREERTOS_CORETIMER_1=y
CONFIG_FREERTOS_HZ=200
CONFIG_FREERTOS_WATCHPOINT_END_OF_STACK=y
# CONFIG_FREERTOS_TASK_FUNCTION_WRAPPER is not set
CONFIG_HEAP_ABORT_WHEN_ALLOCATION_FAILS=y
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y
CONFIG_LWIP_DEBUG=y
CONFIG_LWIP_DEBUG_ESP_LOG=y
CONFIG_LWIP_NETIF_DEBUG=y
CONFIG_LWIP_PBUF_DEBUG=y
CONFIG_LWIP_ETHARP_DEBUG=y
CONFIG_LWIP_API_LIB_DEBUG=y
CONFIG_LWIP_SOCKETS_DEBUG=y
CONFIG_LWIP_IP_DEBUG=y
CONFIG_LWIP_ICMP_DEBUG=y
CONFIG_LWIP_DHCP_STATE_DEBUG=y
CONFIG_LWIP_DHCP_DEBUG=y
CONFIG_LWIP_IP6_DEBUG=y
CONFIG_LWIP_ICMP6_DEBUG=y
CONFIG_LWIP_TCP_DEBUG=y
CONFIG_LWIP_SNTP_DEBUG=y
CONFIG_MBEDTLS_CERTIFICATE_BUNDLE_DEFAULT_CMN=y
CONFIG_MBEDTLS_TLS_CLIENT_ONLY=y
# CONFIG_MQTT_TRANSPORT_WEBSOCKET is not set
CONFIG_NVS_ASSERT_ERROR_CHECK=y
# CONFIG_SPI_FLASH_ENABLE_ENCRYPTED_READ_WRITE is not set
CONFIG_WIFI_PROV_BLE_BONDING=y
CONFIG_WIFI_PROV_BLE_FORCE_ENCRYPTION=y

Debug Logs.

Log

I (39) cpu_start: Pro cpu up.
D (40) efuse: In EFUSE_BLK0__DATA3_REG is used 1 bits starting with 15 bit
D (40) efuse: In EFUSE_BLK0__DATA5_REG is used 1 bits starting with 20 bit
D (40) efuse: In EFUSE_BLK0__DATA3_REG is used 3 bits starting with 9 bit
D (41) efuse: In EFUSE_BLK0__DATA3_REG is used 1 bits starting with 2 bit
I (42) cpu_start: Starting app cpu, entry point is 0x400814d8
0x400814d8: call_start_cpu1 at /esp-idf/components/esp_system/port/cpu_start.c:148

I (0) cpu_start: App cpu up.
D (134) clk: RTC_SLOW_CLK calibration value: 15876751
I (136) cpu_start: Pro cpu start user code
I (136) cpu_start: cpu freq: 240000000
I (136) cpu_start: Application information:
I (136) cpu_start: Project name:     project
I (137) cpu_start: App version:      1
I (137) cpu_start: Compile time:     Jan 26 2023 14:29:02
I (138) cpu_start: ELF file SHA256:  f75937ff3e97fc92...
I (139) cpu_start: ESP-IDF:          9ee3c83-dirty
D (140) memory_layout: Checking 12 reserved memory ranges:
D (140) memory_layout: Reserved memory range 0x3ff81ff0 - 0x3ff82000
D (141) memory_layout: Reserved memory range 0x3ffae000 - 0x3ffae6e0
D (142) memory_layout: Reserved memory range 0x3ffae6e0 - 0x3ffaff10
D (143) memory_layout: Reserved memory range 0x3ffb0000 - 0x3ffb6388
D (143) memory_layout: Reserved memory range 0x3ffb8000 - 0x3ffb9a20
D (144) memory_layout: Reserved memory range 0x3ffbdb28 - 0x3ffbdb5c
D (145) memory_layout: Reserved memory range 0x3ffbdb60 - 0x3ffcb840
D (146) memory_layout: Reserved memory range 0x3ffe0000 - 0x3ffe0440
D (147) memory_layout: Reserved memory range 0x3ffe3f20 - 0x3ffe4350
D (147) memory_layout: Reserved memory range 0x40070000 - 0x40078000
D (148) memory_layout: Reserved memory range 0x40078000 - 0x40080000
0x40080000: _WindowOverflow4 at /esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1739

D (149) memory_layout: Reserved memory range 0x40080000 - 0x4009e764
0x40080000: _WindowOverflow4 at /esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1739

D (150) memory_layout: Building list of available memory regions:
D (151) memory_layout: Available memory region 0x3ffaff10 - 0x3ffb0000
D (151) memory_layout: Available memory region 0x3ffb6388 - 0x3ffb8000
D (152) memory_layout: Available memory region 0x3ffb9a20 - 0x3ffbdb28
D (153) memory_layout: Available memory region 0x3ffcb840 - 0x3ffcc000
D (154) memory_layout: Available memory region 0x3ffcc000 - 0x3ffce000
D (155) memory_layout: Available memory region 0x3ffce000 - 0x3ffd0000
D (156) memory_layout: Available memory region 0x3ffd0000 - 0x3ffd2000
D (156) memory_layout: Available memory region 0x3ffd2000 - 0x3ffd4000
D (157) memory_layout: Available memory region 0x3ffd4000 - 0x3ffd6000
D (158) memory_layout: Available memory region 0x3ffd6000 - 0x3ffd8000
D (159) memory_layout: Available memory region 0x3ffd8000 - 0x3ffda000
D (160) memory_layout: Available memory region 0x3ffda000 - 0x3ffdc000
D (161) memory_layout: Available memory region 0x3ffdc000 - 0x3ffde000
D (161) memory_layout: Available memory region 0x3ffde000 - 0x3ffe0000
D (162) memory_layout: Available memory region 0x3ffe0440 - 0x3ffe3f20
D (163) memory_layout: Available memory region 0x3ffe4350 - 0x3ffe8000
D (164) memory_layout: Available memory region 0x3ffe8000 - 0x3fff0000
D (165) memory_layout: Available memory region 0x3fff0000 - 0x3fff8000
D (165) memory_layout: Available memory region 0x3fff8000 - 0x3fffc000
D (166) memory_layout: Available memory region 0x3fffc000 - 0x40000000
D (167) memory_layout: Available memory region 0x4009e764 - 0x400a0000
I (168) heap_init: Initializing. RAM available for dynamic allocation:
D (169) heap_init: New heap initialised at 0x3ffaff10
I (169) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
D (170) heap_init: New heap initialised at 0x3ffb6388
I (171) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
D (172) heap_init: New heap initialised at 0x3ffb9a20
I (172) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
D (173) heap_init: New heap initialised at 0x3ffcb840
I (174) heap_init: At 3FFCB840 len 000147C0 (81 KiB): DRAM
I (174) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (175) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (176) heap_init: New heap initialised at 0x4009e764
I (177) heap_init: At 4009E764 len 0000189C (6 KiB): IRAM
D (178) FLASH_HAL: extra_dummy: 2
D (178) spi_flash: trying chip: issi
D (178) spi_flash: trying chip: gd
D (179) spi_flash: trying chip: mxic
D (179) spi_flash: trying chip: winbond
D (180) spi_flash: trying chip: generic
I (180) spi_flash: detected chip: generic
I (181) spi_flash: flash io: qio
D (181) chip_generic: set_io_mode: status before 0x200
D (182) cpu_start: calling init function: 0x401b2d68
0x401b2d68: _GLOBAL__sub_I___cxa_get_globals_fast at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/gcc/libstdc++-v3/libsupc++/eh_globals.cc:145

D (183) cpu_start: calling init function: 0x4013e078
0x4013e078: s_set_default_wifi_log_level at /esp-idf/components/esp_wifi/src/wifi_init.c:63

D (183) cpu_start: calling init function: 0x40137e54
0x40137e54: esp_reset_reason_init at /esp-idf/components/esp_system/port/soc/esp32/reset_reason.c:68

D (184) cpu_start: calling init function: 0x4012a254
0x4012a254: esp_ipc_init at /esp-idf/components/esp_ipc/src/esp_ipc.c:105

D (185) cpu_start: calling init function: 0x400d27dc
0x400d27dc: esp_ota_init_app_elf_sha256 at /esp-idf/components/app_update/esp_app_desc.c:68

D (185) intr_alloc: Connected src 17 to int 2 (cpu 0)
I (186) esp_core_dump_uart: Init core dump to UART
D (187) intr_alloc: Connected src 24 to int 3 (cpu 0)
I (187) cpu_start: Starting scheduler on PRO CPU.
D (0) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (0) cpu_start: Starting scheduler on APP CPU.
D (189) heap_init: New heap initialised at 0x3ffe0440
D (189) heap_init: New heap initialised at 0x3ffe4350
D (189) intr_alloc: Connected src 16 to int 9 (cpu 0)

assert failed: xTaskPriorityDisinherit tasks.c:4813 (pxTCB == pxCurrentTCB[xPortGetCoreID()])


Backtrace: 0x40081d72:0x3ffbd340 0x4009310d:0x3ffbd360 0x4009aae9:0x3ffbd380 0x40095d96:0x3ffbd4a0 0x40093765:0x3ffbd4c0 0x40093ce8:0x3ffbd4e0 0x40099d96:0x3ffbd520 0x401ce778:0x3ffbd540 0x401ce8ce:0x3ffbd560 0x40099cf5:0x3ffbd590 0x400d806e:0x3ffbd5e0 0x400d836b:0x3ffbd660 0x401ce5d7:0x3ffbd680
0x40081d72: panic_abort at /esp-idf/components/esp_system/panic.c:408

0x4009310d: esp_system_abort at /esp-idf/components/esp_system/esp_system.c:137

0x4009aae9: __assert_func at /esp-idf/components/newlib/assert.c:85

0x40095d96: xTaskPriorityDisinherit at /esp-idf/components/freertos/tasks.c:4813 (discriminator 1)

0x40093765: prvCopyDataToQueue at /esp-idf/components/freertos/queue.c:2245

0x40093ce8: xQueueGenericSend at /esp-idf/components/freertos/queue.c:854

0x40099d96: esp_log_impl_unlock at /esp-idf/components/log/log_freertos.c:56

0x401ce778: s_log_level_get_and_unlock at /esp-idf/components/log/log.c:162

0x401ce8ce: esp_log_writev at /esp-idf/components/log/log.c:195

0x40099cf5: esp_log_write at /esp-idf/components/log/log.c:210

0x400d806e: initialization at project/main/main.c:161

0x400d836b: app_main at project/main/main.c:359

0x401ce5d7: main_task at /esp-idf/components/freertos/port/port_common.c:141 (discriminator 2)

More Information.

Running on a vanilla ESP32

[igrr]

To not crash, especially before getting to my code.

0x40099cf5: esp_log_write at /esp-idf/components/log/log.c:210
0x400d806e: initialization at project/main/main.c:161
0x400d836b: app_main at project/main/main.c:359
0x401ce5d7: main_task at /esp-idf/components/freertos/port/port_common.c:141 (discriminator 2)

This might totally be a bug in IDF, but from the backtrace it does seem like it gets to initalization in main.c:161. Do you think you could try to narrow down, what particular steps in the initialization function correlate with the crash occurring?

[KaeLL]

[ESP-Marius]

@KaeLL did the above mentioned PR fix your issue?

[KaeLL]

Given the intermittent and trivial nature of the issue, it's too soon to say. Meanwhile, some context like the why and what regarding this issue would be appreciated and educative.

[ESP-Marius]

@KaeLL at the moment we are not sure why the errors are occurring, but the PR do fix something in our newlib component that was inconsistent with the newlib documentation. The feedback so far is that it seems to fix these priority/freertos assert that several users saw.

We have an internal ticket to investigate this deeper, and if we discover something I'll make sure we report back in this issue.