ESP32-S3 IllegalInstruction [Core 0 was running in ISR context] when using xEventGroupClearBitsFromISR

[barrerarodrigo]

Dear support community,

Currently, I have a program for ESP32-S3 Mini configured to run on a single Core [all tasks pinned to core 0; Run FreeRTOS only on first core setted in menuconfig]. I have 7 tasks running and 3 GPIO pin interrupts.

After running my code for about 1 hour, I receive the following backtrace log:

Guru Meditation Error: Core 0 panic'ed (IllegalInstruction). Exception was unhandled.
Memory dump at 0x4200acd4: 10015515 00004055 01051044
0x4200acd4: clear_bits_UHF_RTCM_EG_from_ISR at C:/Users/barre/main/UHF.c:292

Core 0 register dump:
PC : 0x4200acd9 PS : 0x00060031 A0 : 0x00000000 A1 : 0x3fc9d600
0x4200acd9: clear_bits_UHF_RTCM_EG_from_ISR at C:/Users/barre/main/UHF.c:292

A2 : 0x00000001 A3 : 0x00000000 A4 : 0x00000000 A5 : 0x3fcba580
A6 : 0x00000001 A7 : 0x3fcba58c A8 : 0x3fca2320 A9 : 0xff000fff
A10 : 0x00000000 A11 : 0x3fcaabec A12 : 0x00000001 A13 : 0x00000000
A14 : 0x00000040 A15 : 0x00000cbd SAR : 0x00000018 EXCCAUSE: 0x00000000
EXCVADDR: 0x00000000 LBEG : 0x40056f5c LEND : 0x40056f72 LCOUNT : 0x00000000
0x40056f5c: memcpy in ROM

0x40056f72: memcpy in ROM

Core 0 was running in ISR context:
EPC1 : 0x40041a6b EPC2 : 0x4037e3f6 EPC3 : 0x00000000 EPC4 : 0x00000000
0x40041a6b: ets_delay_us in ROM

0x4037e3f6: esp_cpu_wait_for_intr at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_hw_support/cpu.c:121

Backtrace: 0x4200acd6:0x3fc9d600
0x4200acd6: clear_bits_UHF_RTCM_EG_from_ISR at C:/Users/barre/main/UHF.c:292
ELF file SHA256: b45819345746da14

Below I will leave my interrupt code and the code being calleg inside the interrupt:

void IRAM_ATTR TimePulse_isr_handler(void* input_pin){
if(REG_GET_BIT(GPIO_IN1_REG, 256)){
// GPIO_IN1_REG is a 32 bits register. Bit 0 references to pin 32 --> Bit 8 references to PIN 40 which is the Timepulse pin. 2^8=256
clear_bits_UHF_RTCM_EG_from_ISR(BIT0);
}else{
set_bits_UHF_RTCM_EG_from_ISR(BIT0);

}
}

void clear_bits_UHF_RTCM_EG_from_ISR(uint8_t bit){
BaseType_t xResult;

xResult = xEventGroupClearBitsFromISR(UHF_RTCM_EG, bit);
if( xResult == pdPASS ){
portYIELD_FROM_ISR(pdTRUE); // The message was posted successfully.
}
}


By only looking to the backtrace provided and to my code, I cannot see why the crash is happening. However, after looking to the coredump, I noted some things a little bit weird:
-When the crash happened, Thread 2 and Thread 11 both were executing the same code with same spinloc: vPortExitCritical (mux=0x3fc9b790 <xKernelLock>). Would this be allowed? How can we avoid or prevent that from happening?

- Thread 2 is setting a bit on an event group that is different from the one being cleared on the interrupt provided earlier. Thread 11 I do not really know what it does as I understand it was created by esp32 . Can we avoid the creating of esp_timer task?

Initiating core dump!
I (10307) esp_core_dump_uart: Press Enter to print core dump to UART...
I (15307) esp_core_dump_uart: Print core dump to uart...
Core dump started (further output muted)
Received 30 kB...
Core dump finished!
EExceptionxception in thread in thread Thread-1061 (_readerthread):
Tracebac kT (hmorste raecden-t 1c0al6l 0la st():_
Firelaede rt"hrteahd)r:e
Traadcineg.bpya",c lkin e (10most recent call last):
3 8 ,F iilne _"btohortesatdrianpg_.ipnyn"e,r
l i nFei l1e0 38",t hriena d_ibnogo.tpsyt"r,a pl_iinnen e9r7
5, in run
File "threadin gF.ipyl", el i"nseu b9p7r5o,c eiss.pyn r"u, nl
ine 1552, in _rea derthread
File "subprocOSeEsrsr.opry:" ,[ Elrirnneo 12552] 2, in _readerthreadI
nvalid argOSErrorument
: [Errno 22] Invalid argument
===============================================================
==================== ESP32 CORE DUMP START ====================

Crashed task handle: 0x3fcbb8b4, name: '', GDB name: 'process 1070315700'

================== CURRENT THREAD REGISTERS ===================
exccause 0x0 (IllegalInstructionCause)
excvaddr 0x0
epc1 0x4037e417
epc2 0x4037e3f6
epc3 0x0
epc4 0x0
epc5 0x0
epc6 0x0
eps2 0x60020
eps3 0x0
eps4 0x0
eps5 0x0
eps6 0x0
[New process 1070315700]
[New process 1070320200]
[New process 1070310020]
[New process 1070242928]
[New process 1070304940]
[New process 1070255252]
[New process 1070241020]
[New process 1070335936]
[New process 1070330444]
[New process 1070259292]
[New process 1070236448]
[New process 1070270880]
[New process 1070245348]
[Current thread is 1 (process 1070315700)]

==================== CURRENT THREAD STACK =====================


======================== THREADS INFO =========================
pc 0x4200acd9 0x4200acd9 <clear_bits_UHF_RTCM_EG_from_ISR+21>
lbeg 0x40056f5c 1074098012
lend 0x40056f72 1074098034
lcount 0x0 0
sar 0x18 24
ps 0x60021 393249
threadptr <unavailable>
br <unavailable>
scompare1 <unavailable>
acclo <unavailable>
acchi <unavailable>
m0 <unavailable>
m1 <unavailable>
m2 <unavailable>
m3 <unavailable>
expstate <unavailable>
f64r_lo <unavailable>
f64r_hi <unavailable>
f64s <unavailable>
fcr <unavailable>
fsr <unavailable>
a0 0x0 0
a1 0x3fc9d600 1070192128
a2 0x1 1
a3 0x0 0
a4 0x0 0
a5 0x3fcba580 1070310784
a6 0x1 1
a7 0x3fcba58c 1070310796
a8 0x3fca2320 1070211872
a9 0xff000fff -16773121
a10 0x0 0
a11 0x3fcaabec 1070246892
a12 0x1 1
a13 0x0 0
a14 0x40 64
a15 0xcbd 3261
Retrying reading threads information...
Retrying reading threads information...

==================== THREAD 1 (TCB: 0x3fcbb8b4, name: '') =====================
#0 0x4200acd9 in clear_bits_UHF_RTCM_EG_from_ISR (bit=1 '\\001') at C:/Users/barre/main/UHF.c:292

==================== THREAD 2 (TCB: 0x3fcbca48, name: 'UHF_RTCM') =====================
#0 0x400559e0 in ?? ()
#1 0x40384e62 in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:568
#2 vPortExitCritical (mux=0x3fc9b790 <xKernelLock>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:532
#3 0x40383fde in xTaskResumeAll () at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:2688
#4 0x40385b24 in xEventGroupSetBits (xEventGroup=0x3fcaabb8, uxBitsToSet=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/event_groups.c:647
#5 0x4200b4c9 in UHF_BrodacastMessage (Msg=<optimized out>, MsgSize=250) at C:/Users/barre/main/UHF.c:1275
#6 0x4200b544 in uhf_broadcast_pack_and_send () at C:/Users/barre/main/UHF.c:417
#7 0x4200b5c9 in UHF_RtcmRxTask (params=0x0) at C:/Users/barre/main/UHF.c:256
#8 0x40384d00 in vPortTaskWrapper (pxCode=0x4200b548 <UHF_RtcmRxTask>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 3 (TCB: 0x3fcba284, name: 'NMEA') =====================
#0 vTaskDelay (xTicksToDelay=4) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:1681
#1 0x4200b878 in nmea_send_data () at C:/Users/barre/main/wifi_station.c:463
#2 0x4200ba99 in nmea_task () at C:/Users/barre/main/wifi_station.c:424
#3 0x40384d00 in vPortTaskWrapper (pxCode=0x4200ba74 <nmea_task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 4 (TCB: 0x3fca9c70, name: 'IDLE') =====================
#0 0x4037e3f6 in esp_cpu_wait_for_intr () at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_hw_support/cpu.c:121
#1 0x42012b11 in esp_vApplicationIdleHook () at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_system/freertos_hooks.c:59
#2 0x40383940 in prvIdleTask (pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:4327
#3 0x40384d00 in vPortTaskWrapper (pxCode=0x40383934 <prvIdleTask>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 5 (TCB: 0x3fcb8eac, name: 'SERVER') =====================
#0 vTaskDelay (xTicksToDelay=20) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:1681
#1 0x4200c17a in socket_server_task () at C:/Users/barre/main/wifi_station.c:153
#2 0x40384d00 in vPortTaskWrapper (pxCode=0x4200c134 <socket_server_task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 6 (TCB: 0x3fcacc94, name: 'tiT') =====================
#0 0x40383192 in xQueueReceive (xQueue=0x3fcabda0, pvBuffer=0x3fcacaf0, xTicksToWait=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/xtensa/include/xt_utils.h:40
#1 0x4202aa62 in sys_arch_mbox_fetch (mbox=<optimized out>, msg=0x3fcacaf0, timeout=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/lwip/port/freertos/sys_arch.c:317
#2 0x4201aaff in tcpip_timeouts_mbox_fetch (mbox=0x3fca2f78 <tcpip_mbox>, msg=0x3fcacaf0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/lwip/lwip/src/api/tcpip.c:104
#3 0x4201abc1 in tcpip_thread (arg=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/lwip/lwip/src/api/tcpip.c:142
#4 0x40384d00 in vPortTaskWrapper (pxCode=0x4201aba0 <tcpip_thread>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 7 (TCB: 0x3fca94fc, name: 'main') =====================
#0 vTaskDelay (xTicksToDelay=200) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:1681
#1 0x420080d6 in app_main () at C:/Users/barre/main/main.c:34
#2 0x4208c222 in main_task (args=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/app_startup.c:208
#3 0x40384d00 in vPortTaskWrapper (pxCode=0x4208c1ac <main_task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 8 (TCB: 0x3fcc07c0, name: 'RTCM') =====================
#0 0x40383192 in xQueueReceive (xQueue=0x3fcbcf90, pvBuffer=0x3fcc0510, xTicksToWait=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/xtensa/include/xt_utils.h:40
#1 0x420082c8 in RTCM_Task (params=0x0) at C:/Users/barre/main/GNSS.c:180
#2 0x40384d00 in vPortTaskWrapper (pxCode=0x420082ac <RTCM_Task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 9 (TCB: 0x3fcbf24c, name: 'GNSS1') =====================
#0 xEventGroupWaitBits (xEventGroup=0x3fcaa920, uxBitsToWaitFor=3, xClearOnExit=0, xWaitForAllBits=0, xTicksToWait=400) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/event_groups.c:438
#1 0x42009fe8 in GNSS1_Task (params=0x0) at C:/Users/barre/main/GNSS.c:297
#2 0x40384d00 in vPortTaskWrapper (pxCode=0x42009fbc <GNSS1_Task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 10 (TCB: 0x3fcadc5c, name: 'sys_evt') =====================
#0 0x40383192 in xQueueReceive (xQueue=0x3fcace84, pvBuffer=0x3fcada80, xTicksToWait=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/xtensa/include/xt_utils.h:40
#1 0x4208ac58 in esp_event_loop_run (event_loop=0x3fcace5c, ticks_to_run=4294967295) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_event/esp_event.c:569
#2 0x4208ac70 in esp_event_loop_run_task (args=0x3fcace5c) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_event/esp_event.c:107
#3 0x40384d00 in vPortTaskWrapper (pxCode=0x4208ac64 <esp_event_loop_run_task>, pvParameters=0x3fcace5c) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 11 (TCB: 0x3fca8320, name: 'esp_timer') =====================
#0 0x400559e0 in ?? ()
#1 0x40384e62 in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:568
#2 vPortExitCritical (mux=0x3fc9b790 <xKernelLock>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:532
#3 0x403849e5 in ulTaskGenericNotifyTake (uxIndexToWait=0, xClearCountOnExit=1, xTicksToWait=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/tasks.c:5820
#4 0x42006943 in timer_task (arg=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_timer/src/esp_timer.c:475
#5 0x40384d00 in vPortTaskWrapper (pxCode=0x42006934 <timer_task>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 12 (TCB: 0x3fcb09a0, name: 'wifi') =====================
#0 0x40383192 in xQueueReceive (xQueue=0x3fcae888, pvBuffer=0x3fcb07f0, xTicksToWait=<optimized out>) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/xtensa/include/xt_utils.h:40
#1 0x420304c8 in queue_recv_wrapper (queue=0x3fcae888, item=0x3fcb07f0, block_time_tick=4294967295) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/esp_wifi/esp32s3/esp_adapter.c:281
#2 0x42088944 in ppTask ()
#3 0x40384d00 in vPortTaskWrapper (pxCode=0x42088918 <ppTask>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 13 (TCB: 0x3fcaa5e4, name: 'Tmr Svc') =====================
#0 0x40385782 in prvProcessTimerOrBlockTask (xNextExpireTime=<optimized out>, xListWasEmpty=1) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/xtensa/include/xt_utils.h:40
#1 0x403858cf in prvTimerTask (pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/timers.c:619
#2 0x40384d00 in vPortTaskWrapper (pxCode=0x403858c0 <prvTimerTask>, pvParameters=0x0) at C:/Espressif/frameworks/esp-idf-v5.1.1/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162


======================= ALL MEMORY REGIONS ========================
Name Address Size Attrs
.rtc.force_fast 0x600fe010 0x0 RW
.rtc_noinit 0x50000000 0x0 RW
.rtc.force_slow 0x50000000 0x0 RW
.iram0.vectors 0x40374000 0x403 R XA
.iram0.text 0x40374404 0x17267 R XA
.dram0.data 0x3fc9b700 0x56d8 RW A
.flash.text 0x42000020 0x8cb7f R XA
.flash.appdesc 0x3c090020 0x100 R A
.flash.rodata 0x3c090120 0x25964 RW A
.ext_ram.bss 0x3c0c0000 0x0 RW
.iram0.data 0x4038b700 0x0 RW
.iram0.bss 0x4038b700 0x0 RW
.dram0.heap_start 0x3fca6370 0x0 RW
.coredump.tasks.data 0x3fcbb8b4 0x154 RW
.coredump.tasks.data 0x3fcbb590 0x310 RW
.coredump.tasks.data 0x3fcbca48 0x154 RW
.coredump.tasks.data 0x3fcbc710 0x320 RW
.coredump.tasks.data 0x3fcba284 0x154 RW
.coredump.tasks.data 0x3fcb9ff0 0x280 RW
.coredump.tasks.data 0x3fca9c70 0x154 RW
.coredump.tasks.data 0x3fca99d0 0x280 RW
.coredump.tasks.data 0x3fcb8eac 0x154 RW
.coredump.tasks.data 0x3fcb8c20 0x270 RW
.coredump.tasks.data 0x3fcacc94 0x154 RW
.coredump.tasks.data 0x3fcac9a0 0x2e0 RW
.coredump.tasks.data 0x3fca94fc 0x154 RW
.coredump.tasks.data 0x3fca9250 0x290 RW
.coredump.tasks.data 0x3fcc07c0 0x154 RW
.coredump.tasks.data 0x3fcc0410 0x390 RW
.coredump.tasks.data 0x3fcbf24c 0x154 RW
.coredump.tasks.data 0x3fcbefd0 0x260 RW
.coredump.tasks.data 0x3fcadc5c 0x154 RW
.coredump.tasks.data 0x3fcad980 0x2c0 RW
.coredump.tasks.data 0x3fca8320 0x154 RW
.coredump.tasks.data 0x3fca8070 0x290 RW
.coredump.tasks.data 0x3fcb09a0 0x154 RW
.coredump.tasks.data 0x3fcb06d0 0x2b0 RW
.coredump.tasks.data 0x3fcaa5e4 0x154 RW
.coredump.tasks.data 0x3fcaa350 0x280 RW

===================== ESP32 CORE DUMP END =====================
===============================================================


Does anyone have any idea what this crash means and how it could be fixed? Is there any problem to have an interrupt calling xEventGroupClearBitsFromISR while there was a task calling xEventGroupSetBits at the same time? Do we need to protect and avoid this from happening somehow?

Best,

Rodrigo

[ESP_Sprite]

void clear_bits_UHF_RTCM_EG_from_ISR(uint8_t bit){

That's not in IRAM (no IRAM_ATTR), so when that gets called whenever flash is disabled (because it's e.g. written to), the routine is unavailable.

To answer your other questions: it's perfectly acceptable for tasks and ISRs to call into public FreeRTOS functions at the same time; they're re-entrant unless otherwise specified. And two tasks can be in vPortExitCritical at the same time when during the critical section another higher-prio task got unblocked: FreeRTOS will switch to that immediately, leaving the de-scheduled task frozen (for the time) in the tail bit of the vPortExitCritical call.

[barrerarodrigo]

Dear Sprite,

Thank you for your reply.

My interrupt is in fact declared IRAM:

void IRAM_ATTR TimePulse_isr_handler(void* input_pin){
if(REG_GET_BIT(GPIO_IN1_REG, 256)){
// GPIO_IN1_REG is a 32 bits register. Bit 0 references to pin 32 --> Bit 8 references to PIN 40 which is the Timepulse pin. 2^8=256
clear_bits_UHF_RTCM_EG_from_ISR(BIT0);
}else{
set_bits_UHF_RTCM_EG_from_ISR(BIT0);
}
}

However, the function called inside the interrupt is not declared in IRAM:

void clear_bits_UHF_RTCM_EG_from_ISR(uint8_t bit){
BaseType_t xResult;

xResult = xEventGroupClearBitsFromISR(UHF_RTCM_EG, bit);
if( xResult == pdPASS ){
portYIELD_FROM_ISR(pdTRUE); // The message was posted successfully.
}
}

By declaring the interrupt as IRAM, wouldnt it make any function inside it also to run in RAM? Do i need to explicitly declare void clear_bits_UHF_RTCM_EG_from_ISR(uint8_t bit) to be in IRAM as well?

Thank you,

Rodrigo

[ESP_Sprite]

By declaring the interrupt as IRAM, wouldnt it make any function inside it also to run in RAM? Do i need to explicitly declare void clear_bits_UHF_RTCM_EG_from_ISR(uint8_t bit) to be in IRAM as well?

Nope, sorry, you have to declare every function that can be called from the context of an IRAM-safe-declared ISR as IRAM_ATTR.

[barrerarodrigo]

Thank you very much, this solved my problem!