CalledProcessError addr2line returned non-zero exit status 1 (IDFGH-13347)

[nebkat]

Frequently getting crashes in esp-idf-monitor similar to this:

Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0).

Core  0 register dump:
PC      : 0x4037b046  PS      : 0x00050034  A0      : 0x400559e0  A1      : 0x3fc9ca60
0x4037b046: _xt_lowint1 at C:/Espressif/frameworks/esp-idf-v5.2/components/xtensa/xtensa_vectors.S:1240
0x400559e0: _xtos_set_intlevel in ROM

A2      : 0x00000000  A3      : 0x3fc9b2c8  A4      : 0x4037b0a0  A5      : 0x3fc9ca00
0x4037b0a0: _xt_lowint1 at C:/Espressif/frameworks/esp-idf-v5.2/components/xtensa/xtensa_vectors.S:1240

A6      : 0x00000000  A7      : 0x3fcb22d0  A8      : 0x82005425  A9      : 0x00000000
A10     : 0x00000001  A11     : 0x3fcb22b8  A12     : 0x00000000  A13     : 0x00000001
A14     : 0x00000000  A15     : 0x00220000  SAR     : 0x0000000f  EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0xffffffff
0x400570e8: memset in ROM
0x400570f3: memset in ROM

Core  0 was running in ISR context:
EPC1    : 0x42122d03  EPC2    : 0x00000000  EPC3    : 0x00000000  EPC4    : 0x4037b046
0x42122d03: uart_hal_write_txfifo at C:/Espressif/frameworks/esp-idf-v5.2/components/hal/uart_hal_iram.c:27
0x4037b046: _xt_lowint1 at C:/Espressif/frameworks/esp-idf-v5.2/components/xtensa/xtensa_vectors.S:1240



Backtrace: 0x4037b043:0x3fc9ca60 0x400559dd:0x3fca6540 0x40381d7b:0x3fca6550 0x420b6bc9:0x3fca6570 0x420b7427:0x3fca65a0 0x4205b279:0x3fca65d0 0x4205b3c2:0x3fca65f0 0x4205b45b:0x3fca6610 0x4205b491:0x3fca6640 0x4205b4e7:0x3fca6660 0x420101e6:0x3fca6690 0x420103c2:0x3fca6740 0x42016863:0x3fca6760 0x42016c85:0x3fca6890 0x42017209:0x3fca68b0 0x4212e4ce:0x3fca6a60 0x403819d2:0x3fca6a90

Traceback (most recent call last):
  File "C:\Python310\lib\runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "C:\Python310\lib\runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\__main__.py", line 4, in <module>
    main()
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\idf_monitor.py", line 433, in main
    monitor.main_loop()
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\idf_monitor.py", line 179, in main_loop
    self._main_loop()
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\idf_monitor.py", line 295, in _main_loop
    super()._main_loop()
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\idf_monitor.py", line 227, in _main_loop
    self.serial_handler.handle_serial_input(data, self.console_parser, self.coredump,  # type: ignore
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\base\serial_handler.py", line 129, in handle_serial_input
    self.logger.handle_possible_pc_address_in_line(line_strip)
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_monitor\base\logger.py", line 144, in handle_possible_pc_address_in_line
    translation = self.pc_address_decoder.decode_address(line)
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_panic_decoder\pc_address_decoder.py", line 41, in decode_address
    translation = self.lookup_pc_address(num)
  File "C:\Users\Nebojsa\.espressif\python_env\idf5.2_py3.10_env\lib\site-packages\esp_idf_panic_decoder\pc_address_decoder.py", line 58, in lookup_pc_address
    translation = subprocess.check_output(cmd, cwd='.')
  File "C:\Python310\lib\subprocess.py", line 421, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "C:\Python310\lib\subprocess.py", line 526, in run
    raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command '['xtensa-esp32s3-elf-addr2line', '-pfiaC', '-e', 'C:\\project\\build\\esp32s3_dbg\\sunrise.elf', '0x4205b4e7']' returned non-zero exit status 1.
idf_monitor failed with exit code 1, output of the command is in the C:\project\build\esp32s3_dbg\log\idf_py_stderr_output_52176 and C:\project\build\esp32s3_dbg\log\idf_py_stdout_output_52176

Should this also catch CalledProcessError?

esp-idf-panic-decoder/esp_idf_panic_decoder/pc_address_decoder.py

Lines 57 to 64 in 1ca1b96

	try:
	translation = subprocess.check_output(cmd, cwd='.')
	if b'?? ??:0' not in translation:
	decoded = translation.decode()
	return decoded if not is_rom else decoded.replace('at ??:?', 'in ROM')
	except OSError as err:
	red_print(f'{" ".join(cmd)}: {err}')
	return None

Using Python 3.10 on ESP-IDF v5.2.

[Dzarda7]

Hello @nebkat, thank you for pointing out this issue. Let me take a look at it and I will let you know as soon as possible.

[Dzarda7]

Hello @nebkat, you are right. CalledProcessError should be catched. I have prepared fix, can you please provide the code and steps to reproduce as I need to test it? Thanks.

[nebkat]

Hi @Dzarda7,

Thank you very much for the prompt fix!

I will try to reproduce this week but I am not entirely sure why it was occurring in the first place. My suspicion is that it might be happening when you rebuild the elf file while the app is running a previous build or something similar.

I'll see if I can print a fake address or perhaps replace addr2line executable to test.

[Dzarda7]

Thanks for the additional info. I will try to reproduce by myself then. For clarification. There is some error, the fix you started talking about and I am planing to implement will just give you info what is the problem.

[Dzarda7]

I found the problem. You were correct. The panic decoder takes the elf file from build folder even when decoding from serial monitor to decode the backtrace. The problem is when you modify the build folder during running serial monitor with panic error.

If you want to easily reproduce it, just run the code with panic error, monitor output and delete build folder. It will also happen when you open monitor in different project.

Thank you for noticing this, I will catch the exception and try to provide some info to the user.