[Ovmsdev] Crash debugging

[Michael Balzer]

I've pushed an update to enable saving crash data over a reset and automatically send that to the server using the history record "*-OVM-DebugCrash".

Note: you will need to pull the esp-idf as well. As the support for exception handlers was insufficient for our needs, I have added a separate error handler
registration that catches all three kinds of crashes (exceptions, panics and aborts).

Crash reason, registers (if available) and backtrace are available via "boot status", with "make monitor" automatically mapping the addresses:

OVMS# boot status
Last boot was 16 second(s) ago
  This is reset #1 since last power cycle
  Detected boot reason: Crash
  Crash counters: 1 total, 0 early
  CPU#0 boot reason was 12
  CPU#1 boot reason was 12

Last crash: abort() was called on core 1
  Backtrace:
  0x4008f698 0x4008f86f 0x400e7027 0x400edb76 0x400edc8d 0x400edc7f 0x400edcb5 0x400e3908 0x400f11c9 0x400f1230 0x400e3937 0x401cb613 0x400e3f49 0x400e82e5
0x400e84d1 0x400e3df5 0x400e3e04 0x400e69dd
0x4008f698: invoke_abort at /home/balzer/esp/esp-idf/components/esp32/./panic.c:669
0x4008f86f: abort at /home/balzer/esp/esp-idf/components/esp32/./panic.c:669
0x400e7027: module_fault(int, OvmsWriter*, OvmsCommand*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_module.cpp:823
0x400edb76: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edc8d: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edc7f: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edcb5: OvmsCommandApp::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400e3908: Execute(microrl*, int, char const* const*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:47
0x400f11c9: new_line_handler at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/microrl/./microrl.c:620
0x400f1230: microrl_insert_char at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/microrl/./microrl.c:668
0x400e3937: OvmsShell::ProcessChar(char) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:70
0x401cb613: OvmsShell::ProcessChars(char const*, int) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:77
(discriminator 2)
0x400e3f49: ConsoleAsync::HandleDeviceEvent(void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./console_async.cpp:169
0x400e82e5: OvmsConsole::Poll(unsigned int, void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_console.cpp:152
0x400e84d1: OvmsConsole::Service() at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_console.cpp:132 (discriminator 1)
0x400e3df5: ConsoleAsync::Service() at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./console_async.cpp:80
0x400e3e04: non-virtual thunk to ConsoleAsync::Service() at ??:?
0x400e69dd: TaskBase::Task(void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./task_base.cpp:156


The "*-OVM-DebugCrash" record has this structure:

    // H type "*-OVM-DebugCrash"
    //  ,<firmware_version>
    //  ,<bootcount>,<bootreason_name>,<bootreason_cpu0>,<bootreason_cpu1>
    //  ,<crashcnt>,<earlycrashcnt>,<crashtype>,<crashcore>,<registers>,<backtrace>

…with registers and backtraces separated by spaces.

Example:

*-OVM-DebugCrash,0,2592000,3.1.003-11-g37c5f4b/factory/main (build idf v3.1-dev-453-g0f978bcb-dirty Apr  8 2018
14:42:07),1,Crash,12,12,1,0,abort(),1,,0x4008f698 0x4008f86f 0x400e7027 0x400edb76 0x400edc8d 0x400edc7f 0x400edcb5 0x400e3908 0x400f11c9 0x400f1230 0x400e3937
0x401cb613 0x400e3f49 0x400e82e5 0x400e84d1 0x400e3df5 0x400e3e04 0x400e69dd

To decode the backtrace, feed it to addr2line:

balzer at leela:~/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3> xtensa-esp32-elf-addr2line -pfiaC -e build/ovms3.elf 0x4008f698 0x4008f86f 0x400e7027
0x400edb76 0x400edc8d 0x400edc7f 0x400edcb5 0x400e3908 0x400f11c9 0x400f1230 0x400e3937 0x401cb613 0x400e3f49 0x400e82e5 0x400e84d1 0x400e3df5 0x400e3e04
0x400e69dd
0x4008f698: invoke_abort at /home/balzer/esp/esp-idf/components/esp32/./panic.c:669
0x4008f86f: abort at /home/balzer/esp/esp-idf/components/esp32/./panic.c:669
0x400e7027: module_fault(int, OvmsWriter*, OvmsCommand*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_module.cpp:823
0x400edb76: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edc8d: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edc7f: OvmsCommand::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400edcb5: OvmsCommandApp::Execute(int, OvmsWriter*, int, char const* const*) at
/home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_command.cpp:94
0x400e3908: Execute(microrl*, int, char const* const*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:47
0x400f11c9: new_line_handler at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/microrl/./microrl.c:620
0x400f1230: microrl_insert_char at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/microrl/./microrl.c:668
0x400e3937: OvmsShell::ProcessChar(char) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:70
0x401cb613: OvmsShell::ProcessChars(char const*, int) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_shell.cpp:77
(discriminator 2)
0x400e3f49: ConsoleAsync::HandleDeviceEvent(void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./console_async.cpp:169
0x400e82e5: OvmsConsole::Poll(unsigned int, void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_console.cpp:152
0x400e84d1: OvmsConsole::Service() at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./ovms_console.cpp:132 (discriminator 1)
0x400e3df5: ConsoleAsync::Service() at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./console_async.cpp:80
0x400e3e04: non-virtual thunk to ConsoleAsync::Service() at ??:?
0x400e69dd: TaskBase::Task(void*) at /home/balzer/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/main/./task_base.cpp:156


There is also an option to write core dumps in esp-idf, but a core has 64K, and crashes are still too many. I think the backtrace is sufficient in most situations.

We should keep a central archive of .elf files for the releases rolled out, so we don't need to recompile for debugging.

Regards,
Michael

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26