利用 Guru Meditation 错误打印定位问题
目前可先参考 ESP-IDF 编程指南里的 Guru Meditation 错误 来了解常见的错误及对应的原因。此文档包含常见错误的进一步说明及展示一些可行的分析思路。
备注
以下主要以 ESP32-C3 所代表的 RISC-V 架构出现的错误进行分析,ESP32 等 Xtensa 架构对应的错误在命名上会有区别,但错误本质相同,某种架构的一些专属错误会单独分析。
Guru Meditation 错误分为两种类型: ARCH 异常和 SOC 异常。
ARCH 常见异常主要包含以下类型:
Load access fault
Store Access Fault
Instruction Access Fault
IllegalInstruction
SOC 常见异常主要包含以下类型:
Interrupt wdt timeout on CPU0/CPU1
Cache disable but cached memory region accessed
很多时候,Guru Meditation 错误并不能很快的确定原因,因为这些 Guru Meditation crash 只是表象,实际问题会和 FreeRTOS,memory, flash, interrupt 等模块相关,需要具体问题具体分析。
Load access fault(LoadProhibited)
测试用例
使用加载指令(如 lw
)加载无效的内存就会发生此类异常。触发此类 crash 的示例代码如下:
uint8_t *buff = NULL;
load_fault = buff[1];
异常现象
RISC-V
Guru Meditation Error: Core 0 panic'ed (Load access fault). Exception was unhandled.
Core 0 register dump:
Stack dump detected
MEPC : 0x4200696a RA : 0x4200696a SP : 0x3fc8f7c0 GP : 0x3fc8b400
TP : 0x3fc87d74 T0 : 0x4005890e T1 : 0x3fc8f41c T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x0000000f A1 : 0x3fc8f3f8
A2 : 0x00000000 A3 : 0x00000001 A4 : 0x3fc8c000 A5 : 0x00000000
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000005 MTVAL : 0x00000001
XTENSA
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x42007c2f PS : 0x00060a30 A0 : 0x82007c42 A1 : 0x3fc97d70
A2 : 0x42011934 A3 : 0x3c023f48 A4 : 0x3c023fc8 A5 : 0x3fc97d90
A6 : 0x3fc97d70 A7 : 0x0000000c A8 : 0x00000000 A9 : 0x3fc97d20
A10 : 0x0000000f A11 : 0x3fc97fac A12 : 0x3fc97d70 A13 : 0x0000000c
A14 : 0x3fc941e4 A15 : 0x00000000 SAR : 0x00000004 EXCCAUSE: 0x0000001c
Backtrace: 0x42007c2c:0x3fc97d70 0x42007c3f:0x3fc97d90 0x42019247:0x3fc97db0 0x40379e71:0x3fc97de0
定位方法
如果此时进一步分析汇编代码(步骤可参考 附录 1 - ESP 反汇编对应的指令),可以发现能对应到以下指令:
lw a1, 1(zero) // RSIC-V
l8ui a11, a8, 1 // XTENSA
在触发此类异常时,MTVAL/EXCVADDR
会自动更新为与异常有关的数据,从 RISC-V 异常信息中可以看到 MTVAL : 0x00000001
。
一般来说 MTVAL 为 NULL(0x00000000) 代表的是从 NULL 地址取值,而接近 NULL 代表的是尝试从 NULL 地址访问某个数组或者结构体的成员。
对于 RSIC-V 架构来说,PC 和 RA 寄存器包含了异常的函数指针,从 elf 中找出对应的函数排查即可
对于 Xtensa 架构来说,异常时会打印 backtrace,从 elf 中也可以找出对应的函数
实际案例
下图是一个典型的 ESP32-C3 Load access fault 问题。
从上图可以看出,出问题的地方在于 lw a5, 20(s0)
,s0
是 0x0, 这对应了一个 NULL 指针,此时可以继续分析前一句汇编 lw s0, 24(sp)
,对应的代码段为 pxTimer = xMessage.u.xTimerParameters.pxTimer;
,此时问题可变成 pxTimer
为什么为 NULL。
通过添加如下调试日志来进一步定位问题:
if (pxTimer == NULL) {
ets_printf("xMessageID: %d\n", xMessage.xMessageID);
}
最终发现问题在于并未成功创建 timer ,此时 timer 对应的指针为 NULL,此时再执行后续 timer 操作就会因空指针导致此 Load access fault(LoadProhibited)
错误。
注意事项
并不是所有的 Load access fault(LoadProhibited)
问题都可以简单通过上述方法确定出问题的位置,如下图所示:
PC 地址指向了 ROM 函数 rom_i2c_writeReg_mask
函数, 而且 Backtrace 没有足够的有效信息,这种情况下,一般需要能够稳定复现来排查,如果此问题本身很难复现,那么可能是硬件或者野指针问题导致的。
Store access fault(StoreProhibited)
测试用例
当应用程序尝试在无效的内存位置进行写入操作时,会发生此类 CPU 异常,测试代码如下所示:
typedef struct {
uint8_t buf[10];
uint8_t data;
} store_test_t;
void store_access_fault(store_test_t * store_test)
{
store_test->data = 0x5F;
printf("Data: %d\n", store_test->data);
}
void app_main(void)
{
store_test_t * store_test = NULL;
store_access_fault(store_test);
}
异常现象
RISC-V
在 RISC-V 架构的芯片中,可以看到如下异常的打印,通过观察汇编指令(步骤可参考 附录 1 - ESP 反汇编对应的指令)可发现出现这种异常时 PC 地址都指向了 sb/sw
等 store 相关指令。此时 MTVAL 存储的异常值 0x0000000a
说明想要访问的是 NULL 地址开始的某个数组或者结构体里的内容。
Guru Meditation Error: Core 0 panic'ed (Store access fault). Exception was unhandled.
Core 0 register dump:
Stack dump detected
MEPC : 0x42006960 RA : 0x42006984 SP : 0x3fc8f7c0 GP : 0x3fc8b400
TP : 0x3fc87d7c T0 : 0x4005890e T1 : 0x20000000 T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x00000000 A1 : 0x3fc8f3f8
A2 : 0x00000000 A3 : 0x00000001 A4 : 0x3fc8c000 A5 : 0x0000005f
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000007 MTVAL : 0x0000000a
XTENSA
在 XTENSA 架构的芯片中,可以看到下列异常打印,通过观察汇编指令(步骤可参考 附录 1 - ESP 反汇编对应的指令)可发现出现这种异常时 PC 地址都指向了 s8i/s32i
等 store 相关的指令。此时 EXCVADDR
存储的异常值 0x0000000a
说明想要访问的是 NULL 地址开始的某个数组或者结构体里的内容。
Guru Meditation Error: Core 0 panic'ed (StoreProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x42007c21 PS : 0x00060630 A0 : 0x82007c38 A1 : 0x3fc97d70
A2 : 0x00000000 A3 : 0x3c023f48 A4 : 0x3c023fc8 A5 : 0x3fc97d90
A6 : 0x3fc97d70 A7 : 0x0000000c A8 : 0x0000005f A9 : 0x3fc97d00
A10 : 0x00000031 A11 : 0x3fc97fac A12 : 0x3fc97d70 A13 : 0x0000000c
A14 : 0x3fc941e4 A15 : 0x00000000 SAR : 0x00000004 EXCCAUSE: 0x0000001d
EXCVADDR: 0x0000000a LBEG : 0x400556d5 LEND : 0x400556e5 LCOUNT : 0xfffffffd
Backtrace: 0x42007c1e:0x3fc97d70 0x42007c35:0x3fc97d90 0x4201923f:0x3fc97db0 0x40379e71:0x3fc97de0
定位方法
定位方法与 Load access fault(LoadProhibited) 类似,如果此时观察汇编代码(步骤可参考 附录 1 - ESP 反汇编对应的指令)会看到如下指令:
sb a5,10(a0) // RSIC-V
s8i a8, a2, 10 // XTENSA
在触发此类异常时,MTVAL/EXCVADDR
会自动更新为与异常有关的数据,从 RISC-V 异常信息中可以看到 MTVAL : 0x0000000a
。一般来说 MTVAL 为 NULL 代表 CPU 尝试向 NULL 地址写数据,而接近 NULL 代表的是尝试向 NULL 地址开始的某个数组或者结构体的成员中写数据。
对于 RSIC-V 架构,PC 和 RA 寄存器包含了异常的函数指针,从 elf 中找出对应的函数排查即可
对于 Xtensa 架构,异常时会打印 backtrace,从 elf 中也可以找出对应的函数排查
实际案例
请参考 测试用例。
注意事项
与 Load access fault(LoadProhibited) 问题类似,存在野指针导致无法解析的情况,此时需要根据实际应用代码进一步分析。
Instruction Access Fault(InstrFetchProhibited)
测试用例
当应用程序尝试从无效的地址读取指令时,会发生此类 CPU 异常,此时 PC 寄存器往往会指向无效的内存地址,测试代码如下所示:
typedef void (*fptr_t)(void);
volatile fptr_t fptr = (fptr_t) 0x4;
fptr();
对应的 RISC-V 汇编指令(步骤可参考 附录 1 - ESP 反汇编对应的指令)如下:
42006958: 1101 addi sp,sp,-32
4200695a: ce06 sw ra,28(sp)
4200695c: 4791 li a5,4
4200695e: c63e sw a5,12(sp)
42006960: 47b2 lw a5,12(sp)
42006962: 9782 jalr a5
42006964: 40f2 lw ra,28(sp)
42006966: 6105 addi sp,sp,32
42006968: 8082 ret
异常现象
RISC-V
Guru Meditation Error: Core 0 panic'ed (Instruction access fault). Exception was unhandled.
Core 0 register dump:
Stack dump detected
MEPC : 0x00000004 RA : 0x42006964 SP : 0x3fc8f7b0 GP : 0x3fc8b400
TP : 0x3fc87d8c T0 : 0x4005890e T1 : 0x20000000 T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x00000031 A1 : 0x3fc8f3f8
A2 : 0x00000000 A3 : 0x00000001 A4 : 0x3fc8c000 A5 : 0x00000004
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000001 MTVAL : 0x00000004
Xtensa
Guru Meditation Error: Core 0 panic'ed (InstrFetchProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x00000004 PS : 0x00060630 A0 : 0x800d539a A1 : 0x3ffb4a30
A2 : 0x400de738 A3 : 0x3f40379c A4 : 0x3f40381c A5 : 0x3ffb4a60
A6 : 0x3ffb4a40 A7 : 0x0000000c A8 : 0x800e4dbe A9 : 0x3ffb49d0
A10 : 0x00000031 A11 : 0x3ffafc64 A12 : 0x3ffb4a40 A13 : 0x0000000c
A14 : 0x3ffb2770 A15 : 0x0000cdcd SAR : 0x00000004 EXCCAUSE: 0x00000014
EXCVADDR: 0x00000004 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xfffffffd
Backtrace: 0x00000001:0x3ffb4a30 0x400d5397:0x3ffb4a60 0x400e54f8:0x3ffb4a80 0x400858e9:0x3ffb4ab0
定位方法
一般来说,此类问题都是由野指针导致的,此时 PC 寄存器已经没有价值,其他寄存器是否值得分析取决于野指针运行的时间,对于此用例来说,因为在当前函数已经触发 CPU 异常,因此 RA 寄存器中包含了上层函数指针(Xtensa 架构通过 Backtrace),此时可以分析出来异常。但是大多数时间, RA 寄存器也会被破坏,此时如果需要分析,可以根据如下步骤进行:
稳定复现问题,保证每次出现的问题相同
找寻问题的规律,比如执行哪些操作,或者打印哪些日志后开始异常
根据程序异常的位置来结合代码分析,通过加调试日志以及逐步减少工程的代码量来看是否仍能复现问题
实际案例
如下图所示,异常时的现场已经完全被破坏,通过这些信息,没有办法去反推问题的原因,不过大多数寄存器都被破坏成一个固定值本身也是一个规律,像这种寄存器全被破坏的情况,一般是内存踩踏导致的问题,可以用 堆内存调试 的方法进行分析。
Illegal Instruction
测试用例
CPU 取指阶段,取到非法指令(RISC-V spec 中定义为 16 bit 全为 0 的指令)会打印此错误。测试代码如下所示:
uint32_t instr_dram_addr = 0x0;
intptr_t instr_addr = MAP_DRAM_TO_IRAM((intptr_t)&instr_dram_addr);
typedef void (*illegal_instr_t)(void);
illegal_instr_t illegal_instr = (uint32_t *)instr_addr; // 确保 instr_addr 内存数据为 0x0
illegal_instr();
备注
Xtensa 平台中的 ESP32 不支持上述测试用例,其他芯片如要运行此测试用例,需要先关闭内存保护功能。
异常现象
RISC-V
Guru Meditation Error: Core 0 panic'ed (Illegal instruction). Exception was unhandled.
Core 0 register dump:
Stack dump detected
MEPC : 0x4005f002 RA : 0x42006962 SP : 0x3fc8f7c0 GP : 0x3fc8b400
0x42006962: illegal_instr_fault at /home/jacques/useful_example/crash_sim/store_access_fault/main/hello_world_main.c:79
TP : 0x3fc87d8c T0 : 0x4005890e T1 : 0x20000000 T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x3fc8f840 A1 : 0x3fc8f3f8
A2 : 0x00000000 A3 : 0x00000001 A4 : 0x3fc8c000 A5 : 0x4005f000
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000002 MTVAL : 0x00000000
Xtensa
Guru Meditation Error: Core 0 panic'ed (IllegalInstruction). Exception was unhandled.
Memory dump at 0x403e298c: 00000000 00000000 00000000
Core 0 register dump:
PC : 0x403e2990 PS : 0x00060130 A0 : 0x820059fe A1 : 0x3fcf2990
A2 : 0x4200c030 A3 : 0x3c0232fc A4 : 0x3c02337c A5 : 0x3fcf29c0
A6 : 0x3fcf29a0 A7 : 0x0000000c A8 : 0x820059f4 A9 : 0x3fcf2930
A10 : 0x00000031 A11 : 0x3fcf2be4 A12 : 0x3fcf29a0 A13 : 0x0000000c
A14 : 0x3fc922c4 A15 : 0x00000000 SAR : 0x00000004 EXCCAUSE: 0x00000000
EXCVADDR: 0x00000000 LBEG : 0x400556d5 LEND : 0x400556e5 LCOUNT : 0xfffffffd
Backtrace: 0x403e298d:0x3fcf2990 |<-CORRUPTED
定位方法
虽然在 ESP-IDF 文档中有 Illegal instruction 说明 ,其中提到可能有 3 类情况触发此问题 ,但是实际使用中,大多数都是 CPU 从 flash 取指令异常触发此问题,还有一部分是类似测试用例这种野指针导致的从内存取值异常,从 PC 地址一般可以看出是从 IRAM 还是从 flash 取址异常。
从 flash 取指出现问题可能的原因包括 ESP 芯片休眠时 flash 下电、CS 上拉不稳定,flash 供电不稳定,以及 flash suspend 功能等。
实际案例
下图是 ESP 芯片在低功耗场景下的一种异常情况,从日志中可以看到异常前有 power save 的打印,可以怀疑问题跟芯片休眠有关。后在 menuconfig 配置项中关闭休眠时给 flash 掉电(CONFIG_ESP_SLEEP_POWER_DOWN_FLASH),以及开启休眠时 CS 软件上拉(CONFIG_ESP_SLEEP_FLASH_LEAKAGE_WORKAROUND) 这两个选项 ,问题不再复现。
Cache disable but cached memory region accessed(Cache error)
异常原理
在 flash 操作(读写擦)时会关闭 cache ,如果此时中断触发 (使用 ESP_INTR_FLAG_IRAM
修饰的中断可以在 cache 关闭的时候触发),如中断函数中存在函数需要通过 cache 从 flash 中取指或取数据(包括mmap
),会因为 cache 被关闭导致异常。
测试用例
在关闭 cache 后,访问并打印 flash 中的数据。测试代码如下所示:
static const uint32_t s_in_rodata[8] = { 0x12345678, 0xfedcba98 };
spi_flash_disable_interrupts_caches_and_other_cpu();
volatile uint32_t* src = (volatile uint32_t*) s_in_rodata;
uint32_t v1 = src[0];
uint32_t v2 = src[1];
ets_printf("%lx %lx\n", v1, v2);
异常现象
RISC-V
Guru Meditation Error: Core 0 panic'ed (Cache error).
access to cache while dbus or cache is disabled
Stack dump detected
Core 0 register dump:
MEPC : 0x40000040 RA : 0x40381e82 SP : 0x3fc8f7c0 GP : 0x3fc8b400
0x40381e82: cache_access_test_func at /home/jacques/useful_example/crash_sim/store_access_fault/main/hello_world_main.c:38
TP : 0x3fc87d5c T0 : 0x4005890e T1 : 0x20000000 T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x3c025610 A1 : 0x00000000
A2 : 0x00000000 A3 : 0x00000200 A4 : 0x600c4000 A5 : 0x3c02561c
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000019 MTVAL : 0x6944806f
Xtensa
Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed).
Core 0 register dump:
PC : 0x400830ed PS : 0x00060a34 A0 : 0x800d539a A1 : 0x3ffb4a40
0x400830ed: cache_access_test_func at /home/jacques/useful_example/crash_sim/store_access_fault/main/hello_world_main.c:32
A2 : 0x400de738 A3 : 0x3f40379c A4 : 0x3f40381c A5 : 0x3ffb4a60
0x400de738: vprintf at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vprintf.c:30
A6 : 0x3ffb4a40 A7 : 0x0000000c A8 : 0x3f4040c4 A9 : 0x3ffb4a10
A10 : 0x00000001 A11 : 0xbad00bad A12 : 0x3ffb2608 A13 : 0x0000000c
A14 : 0x3ffb2770 A15 : 0x0000cdcd SAR : 0x00000004 EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xfffffffd
Backtrace: 0x400830ea:0x3ffb4a40 0x400d5397:0x3ffb4a60 0x400e54e4:0x3ffb4a80 0x40085915:0x3ffb4ab0
分析方法
在出现此类问题,主要观察异常时的 PC 地址,如果地址在 flash 中,说明在关闭 cache 的时候从 flash 读指令,此时只需要把对应的函数使用 IRAM_ATTR
修饰即可,需要注意的是 IRAM_ATTR
只针对当前函数,如果此函数还有子函数,那么子函数也需要使用 IRAM_ATTR
进行修饰。
如果地址在 IRAM 中,说明此函数本身没问题,可能是此函数对应的输入参数等需要从 flash 中读取。
实际案例
在 flash 读写操作(导致 cache 关闭)时已放入 IRAM 的 gptimer 中断也触发,gptimer ISR 里执行了一些需要从 flash 读取内容的操作触发此问题:
从上述截图我们可以观察到几个问题点
可确定问题为在 flash 读写操作的时候触发了 gptimer 中断,且 ISR 里有存在于 flash 里的内容
异常时 PC 指向的函数
gpio_set_level
已放入 IRAM,而不是在 flash 中,因此不需要经过 cache,在 cache 关闭时也应正常运行
经过分析,最终排查到是函数 gpio_set_level
的输入参数 LED_matrix
使用 const 修饰导致的,被 const 修饰的参数会放置在 flash 的 .rodata 段,因此读取此参数需通过 cache。
注意事项
Cache disable 的异常在 Xtensa 平台上捕捉的更好,在 RISC-V 平台上可能会表现为因 cache 读不到数据导致的其他错误,如 Illegal instruction. 代码示例如下:
gpio_set_level(12, 1);
spi_flash_disable_interrupts_caches_and_other_cpu();
gpio_set_level(12, 0);
在 ESP32-C3(RISC-V 平台) 中运行时,出现的 crash 如下
Guru Meditation Error: Core 0 panic'ed (Illegal instruction). Exception was unhandled.
Core 0 register dump:
Stack dump detected
MEPC : 0x42006ef2 RA : 0x40381e7e SP : 0x3fc8f7f0 GP : 0x3fc8b400
0x42006ef2: gpio_set_level at /home/jacques/sdk/esp-idf/components/driver/gpio/gpio.c:233
0x40381e7e: cache_access_test_func at /home/jacques/useful_example/crash_test/main/hello_world_main.c:50
TP : 0x3fc87d4c T0 : 0x4005890e T1 : 0x20000000 T2 : 0x00000000
S0/FP : 0x3c023000 S1 : 0x00000000 A0 : 0x0000000c A1 : 0x00000000
A2 : 0x00000200 A3 : 0x00000200 A4 : 0x600c4000 A5 : 0x00000000
A6 : 0x60023000 A7 : 0x0000000a S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000002 MTVAL : 0x00000000
Interrupt wdt timeout on CPU0/CPU1
异常原理
中断看门狗使用 Timer group 1 上的硬件看门狗定时器,通过在滴答定时器 SysTick 中断中添加喂狗操作来监控系统任务调度是否正常。当长时间(默认 300 ms)未在 SysTick 中断中做喂狗处理时,中断看门狗中断触发。更多信息请参考 Interrupt Watchdog Timer (IWDT)。
测试用例
可以通过关中断的方式来触发此问题,测试代码如下所示:
static portMUX_TYPE s_init_spinlock = portMUX_INITIALIZER_UNLOCKED;
portENTER_CRITICAL(&s_init_spinlock);
while (1) {
}
异常现象
RISC-V
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).
Core 0 register dump:
Stack dump detected
MEPC : 0x42006964 RA : 0x42006964 SP : 0x3fc911a0 GP : 0x3fc8b400
0x42006964: interrupt_wdt_fault_task at /home/jacques/useful_example/crash_test/main/hello_world_main.c:121 (discriminator 1)
TP : 0x3fc8971c T0 : 0x00000000 T1 : 0x00000000 T2 : 0x00000000
S0/FP : 0x00000000 S1 : 0x00000000 A0 : 0x00000001 A1 : 0x00000000
A2 : 0x00000000 A3 : 0x00000004 A4 : 0x00000001 A5 : 0x3fc8c000
A6 : 0x00000000 A7 : 0x00000000 S2 : 0x00000000 S3 : 0x00000000
S4 : 0x00000000 S5 : 0x00000000 S6 : 0x00000000 S7 : 0x00000000
S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x00000000 T4 : 0x00000000 T5 : 0x00000000 T6 : 0x00000000
MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000018 MTVAL : 0x0000a001
Xtensa
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).
Core 0 register dump:
PC : 0x40378b06 PS : 0x00060634 A0 : 0x82002239 A1 : 0x3fc984f0
0x40378b06: esp_cpu_wait_for_intr at /home/jacques/sdk/esp-idf/components/esp_hw_support/cpu.c:110
A2 : 0x00000000 A3 : 0x00000000 A4 : 0x3fc96c70 A5 : 0x3fc96c50
A6 : 0x42005e10 A7 : 0x00000000 A8 : 0x82009452 A9 : 0x3fc984b0
0x42005e10: timer_task at /home/jacques/sdk/esp-idf/components/esp_timer/src/esp_timer.c:470
A10 : 0x00000000 A11 : 0x00000000 A12 : 0x3fc96c50 A13 : 0x3fc96c30
A14 : 0x00000000 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Backtrace: 0x40378b03:0x3fc984f0 0x42002236:0x3fc98510 0x4037b5a9:0x3fc98530 0x40379e71:0x3fc98550
0x40378b03: xt_utils_wait_for_intr at /home/jacques/sdk/esp-idf/components/xtensa/include/xt_utils.h:81
(inlined by) esp_cpu_wait_for_intr at /home/jacques/sdk/esp-idf/components/esp_hw_support/cpu.c:101
0x42002236: esp_vApplicationIdleHook at /home/jacques/sdk/esp-idf/components/esp_system/freertos_hooks.c:59
0x4037b5a9: prvIdleTask at /home/jacques/sdk/esp-idf/components/freertos/FreeRTOS-Kernel/tasks.c:4269 (discriminator 1)
0x40379e71: vPortTaskWrapper at /home/jacques/sdk/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:149
Core 1 register dump:
PC : 0x42007c32 PS : 0x00060034 A0 : 0x80379e74 A1 : 0x3fc99f20
0x42007c32: interrupt_wdt_fault_task at /home/jacques/useful_example/crash_test/main/hello_world_main.c:121 (discriminator 1)
A2 : 0x00000000 A3 : 0x00000000 A4 : 0x00000001 A5 : 0x00000000
A6 : 0x00000001 A7 : 0x00000000 A8 : 0x82007c32 A9 : 0x3fc99ef0
A10 : 0x00000001 A11 : 0x3fc93a54 A12 : 0x00060020 A13 : 0x00060023
A14 : 0x00060323 A15 : 0x0000abab SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Backtrace: 0x42007c2f:0x3fc99f20 0x40379e71:0x3fc99f40
0x42007c2f: vPortEnterCritical at /home/jacques/sdk/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:573
(inlined by) interrupt_wdt_fault_task at /home/jacques/useful_example/crash_test/main/hello_world_main.c:120
0x40379e71: vPortTaskWrapper at /home/jacques/sdk/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:149
分析方法
在出现此类问题,主要观察异常时的 PC 地址,即可确定触发 crash 的位置。对于多核架构,需要观察几个核心的寄存器,分析其中触发问题的方法。
可能的原因及具体解释如下:
长时间关中断
ISR 函数中存在阻塞
没有清中断
长时间关中断
关中断操作本身是为了保护一些不能中途停止执行的程序而设计的,它用来禁止系统响应中断源的中断请求。长时间关中断是导致中断看门狗触发的最主要原因。
如 测试用例 中进入临界区的操作会关闭中断。关中断之后, SysTick 中断无法触发来及时进行喂狗操作,这后续会导致中断看门狗超时(关中断无法屏蔽看门狗中断)并触发看门狗异常处理程序,此时需要用户自己排查上层关中断的逻辑,依据出问题的代码位置进一步分析。
ISR 函数中存在阻塞
在 ESP 芯片产生某一中断之后,会调用对应的 ISR 进行处理,在 ISR 函数中应做的操作应尽可能少,可以将需要耗时的操作转移到其他非中断函数中处理。如 ISR 函数需耗费大量时间来运行或存在阻塞导致未在中断看门狗触发前退出 ISR,就会触发异常。
以下是 GPIO ISR 阻塞的一个简单示例:
#define GPIO_INPUT_IO_0 4
static void IRAM_ATTR gpio_isr_handler(void* arg)
{
ets_printf("ISR\n");
while(1){}
}
void app_main(void)
{
gpio_config_t io_conf;
io_conf.intr_type = GPIO_INTR_POSEDGE;
io_conf.pin_bit_mask = (1ULL<<GPIO_INPUT_IO_0);
io_conf.mode = GPIO_MODE_INPUT;
io_conf.pull_up_en = 1;
gpio_config(&io_conf);
gpio_install_isr_service(0);
gpio_isr_handler_add(GPIO_INPUT_IO_0, gpio_isr_handler, (void*) GPIO_INPUT_IO_0);
}
将 GPIO 4 手动拉高,触发 GPIO 中断,打印如下 crash 信息:
ISR
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).
Core 0 register dump:
PC : 0x40082580 PS : 0x00060034 A0 : 0x80081560 A1 : 0x3ffb07c0
0x40082580: gpio_isr_handler at /home/jacques/problem/wdt/int_wdt/build/../main/hello_world_main.c:40 (discriminator 1)
A2 : 0x00000004 A3 : 0x3ff0015c A4 : 0x800d6d82 A5 : 0x3ffb3400
A6 : 0x00000000 A7 : 0x00000001 A8 : 0x80082580 A9 : 0x3ffb0730
A10 : 0x00000004 A11 : 0x00000004 A12 : 0x00000004 A13 : 0x00000000
A14 : 0x00000000 A15 : 0x3ffb3400 SAR : 0x0000001c EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Core 0 was running in ISR context:
EPC1 : 0x400d1097 EPC2 : 0x00000000 EPC3 : 0x00000000 EPC4 : 0x40082580
0x400d1097: uart_hal_write_txfifo at /home/jacques/sdk/esp-idf/components/hal/uart_hal_iram.c:35
0x40082580: gpio_isr_handler at /home/jacques/problem/wdt/int_wdt/build/../main/hello_world_main.c:40 (discriminator 1)
Backtrace:0x4008257d:0x3ffb07c0 0x4008155d:0x3ffb07e0 0x40082102:0x3ffb0800 0x400d6702:0x3ffb3450 0x400862a2:0x3ffb3470 0x40087865:0x3ffb3490
通过 PC 和 Backtrace,我们可以确认问题出现在 gpio_isr_handle 函数中。此外, Core 0 was running in ISR context
这行日志也表明当前在中断函数中运行。
没有清中断
在 ISR 函数结束后,需要手动清除相应的中断,如果此时不做清除,中断将会一直触发,从而使得 Systick 中断无法响应。
如 ISR 函数中存在阻塞 里的示例,如果把 gpio_isr_handler
中的 while(1) 循环去掉, 然后将 ESP-IDF GPIO 驱动中的 gpio_hal_clear_intr_status_bit 注释后重新编译烧写运行上述程序,可以发现同样触发了中断看门狗的 crash。
如果用户没有自行修改默认驱动,清中断一般来说会由驱动底层自行完成,若此时出现了指向内部驱动的中断看门狗异常,则可以进一步查看驱动底层是否正常做了清中断操作。
实际案例
通过上述描述,可能会认为中断看门狗问题极易分析,但实际的应用中中断看门狗问题往往非独立存在,一般会跟 FreeRTOS 相结合,FreeRTOS 很多操作都需要关中断处理,一旦 FreeRTOS 出现异常则容易卡住并表现为中断看门狗问题,实际 crash 案例如下:
Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0)
Core 0 register dump:
PC : 0x400915d2 PS : 0x00060b34 A0 : 0x800903ed A1 : 0x3ffd4e80
A2 : 0x3ffd3598 A3 : 0x3ffd4ff0 A4 : 0x00000c9f A5 : 0x3f408990
A6 : 0x3ffbf580 A7 : 0x00060023 A8 : 0x3ffd4ff0 A9 : 0x0000000f
A10 : 0x3ffd4ff0 A11 : 0x0000000f A12 : 0x00060b20 A13 : 0x00000001
A14 : 0x3ffeddf0 A15 : 0x3ffea57c SAR : 0x00000018 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xfffffffe
ELF file SHA256: eadf38922e335ed1
Backtrace: 0x400915cf:0x3ffd4e80 0x400903ea:0x3ffd4ea0 0x4008f514:0x3ffd4ec0 0x400ffb91:0x3ffd4f00 0x40136612:0x3ffd4f30
解析 Backtrace 信息,如下:
~$ xtensa-esp32-elf-addr2line -afe esp32_interrupt_wdt.elf 0x400915cf:0x3ffd4e80 0x400903ea:0x3ffd4ea0 0x4008f514:0x3ffd4ec0 0x400ffb91:0x3ffd4f00 0x40136612:0x3ffd4f30
0x400915cf
vListInsert
/arm/esp-idf/components/freertos/list.c:205
0x400903ea
vTaskPlaceOnEventList
/arm/esp-idf/components/freertos/tasks.c:2901 (discriminator 2)
0x4008f514
xQueueGenericReceive
/arm/esp-idf/components/freertos/queue.c:1596
0x400ffb91
arch_os_mbox_fetch
/arm/components/esp32/arch_os.c:352 (discriminator 4)
0x40136612
msg_fetch_block
/arm/components/libs/d0/delayzero.c:631
通过上述日志可看出问题并不是 crash 在中断里,而是指向了 FreeRTOS 本身,通过查找 vListInsert 可发现在以下 for 循环里出现问题:
if( xValueOfInsertion == portMAX_DELAY )
{
pxIterator = pxList->xListEnd.pxPrevious;
}
else
{
for( pxIterator = ( ListItem_t * ) &( pxList->xListEnd ); pxIterator->pxNext->xItemValue <= xValueOfInsertion; pxIterator = pxIterator->pxNext )
{
/* There is nothing to do here, just iterating to the wanted
insertion position. */
}
}
此时可进一步检查对应上层代码在此刻是否有关中断操作,最后在 vTaskPlaceOnEventList 中可看到确实是先关中断,再去执行的链表插入操作。
void vTaskPlaceOnEventList( List_t * const pxEventList, const TickType_t xTicksToWait )
{
configASSERT( pxEventList );
taskENTER_CRITICAL(&xTaskQueueMutex);
vListInsert( pxEventList, &( pxCurrentTCB[xPortGetCoreID()]->xEventListItem ) );
prvAddCurrentTaskToDelayedList( xPortGetCoreID(), xTicksToWait);
taskEXIT_CRITICAL(&xTaskQueueMutex);
}
至此分析完成,此问题是一个表现为中断看门狗的 FreeRTOS 问题,因此排查这个问题需要分析为什么会在 for 循环中不再退出。FreeRTOS 本身出现问题的概率极低,此时大多数是由于上层应用代码使用不当导致的,可能的原因包括内存踩踏,关中断后调用阻塞操作等问题。
附录 1 - ESP 反汇编对应的指令
Xtensa ESP32 :
xtensa-esp32-elf-objdump -S xxx.elf > a.txt
Xtensa ESP32-S2 :
xtensa-esp32s2-elf-objdump -S xxx.elf > a.txt
Xtensa ESP32-S3 :
xtensa-esp32s3-elf-objdump -S xxx.elf > a.txt
RISC-V :
riscv32-esp-elf-objdump -S xxx.elf > a.txt
其中 xxx.elf
为工程 elf 文件,此文件往往在工程目录下的 build 文件夹里。 a.txt
为反汇编的输出问题,里面包含了实际的汇编指令。