Иногда уже после сборки и отладки очередного устройства, а затем и установки его “на место”, вдруг начинают проявляться самопроизвольные перезагрузки из-за паники. Это означает, что в прошивке где-то присутствует ранее незамеченная проблема. Возникает задача: определить место возникновения сбоя. Зная файл исходного кода и номер строки, можно с большой степенью вероятности предположить причину проблемы и устранить её. При локальной отладке в случае сбоя паники в COM-порт обычно печатается backtrace, который можно “расшифровать” и выяснить место точку возникновения проблемы. Как это сделать, я писал в предыдущей статье.
Core 1 register dump: PC : 0x400e14ed PS : 0x00060030 A0 : 0x800d0805 A1 : 0x3ffb5030 A2 : 0x00000000 A3 : 0x00000001 A4 : 0x00000001 A5 : 0x3ffb50dc A6 : 0x00000000 A7 : 0x00000001 A8 : 0x00000000 A9 : 0x3ffb5000 A10 : 0x00000000 A11 : 0x3ffb2bac A12 : 0x40082d1c A13 : 0x06ff1ff8 A14 : 0x3ffb7078 A15 : 0x00000000 SAR : 0x00000014 EXCCAUSE: 0x0000001d EXCVADDR: 0x00000000 LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0xffffffff Backtrace: 0x400e14ed:0x3ffb5030 0x400d0802:0x3ffb5050
Осталось получить этот самый backtrace после сбоя. Если доступ к устройству имеется, можно подключиться к USB / COM-порту и проследить вывод логов. Но и при доступе к устройству так же могут быть некоторые сложности – ошибка может возникать раз в неделю или реже, в этом случае “мониторить” устройство через COM-порт становится проблематично. В PlatformIO имеется возможность сохранять отладочный вывод в COM-порт в файл, можно использовать этот способ.
Гораздо хуже, если физического доступа к устройству нет – например, если оно физически расположено в другом населенном пункте или в труднодоступном месте. В таком случае отладка возможна, только если устройство самостоятельно отправит какие-либо данные для отладки в telegram, на mqtt-брокер или куда-либо ещё. Проблема в том, что на текущий момент ни framework-espidf, ни framework-arduinoespressif32 не предусматривают сохранение backtrace куда-либо, кроме COM-порта. Придется “колхозить” перехват и сохранение backtrace самостоятельно.
Массив для сохранения backtrace
Под сохранение backtrace достаточно выделить сравнительно небольшой массив uint32_t чисел. Размер массива зависит от того, сколько адресов нужно там хранить. Обычно достаточно 10-16 ячеек, но в некоторых особо тяжелых случаях нужно и больше (например если перезагрузка возникает при ошибке выделения памяти, когда куча исчерпана – в этом случае в начале backtrace будут вызовы системных функций выделения памяти). Я определил этот массив так:
#if CONFIG_RESTART_DEBUG_INFO typedef struct { size_t heap_total; size_t heap_free; size_t heap_free_min; time_t heap_min_time; #if CONFIG_RESTART_DEBUG_STACK_DEPTH > 0 uint32_t backtrace[CONFIG_RESTART_DEBUG_STACK_DEPTH]; #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH } re_restart_debug_t; #endif // CONFIG_RESTART_DEBUG_INFO
С помощью макроса CONFIG_RESTART_DEBUG_INFO можно включать или отключать сохранение отладочной информации, с помощью макроса CONFIG_RESTART_DEBUG_STACK_DEPTH можно устнавливать размер буфера под сохранение backtrace. Кроме того, сохраняются данные о размере свободной кучи.
Возникает вопрос в том, где сохранить эти данные при перезагрузке.
Первая мысль – сохранить во flash памяти, например в NVS-разделе. Но, увы, это не всегда прокатывает, так как не удается выполнить запись.
В итоге я поступил по другому – пометил данные для отладке модификатором __NOINIT_ATTR. Это заставит компилятор поместить данный блок данных в область, которая не очищается при перезагрузке. Конечно, при выключении и включении устройства данные будут утеряны в любом случае, но в этом случае они не требуются.
#if CONFIG_RESTART_DEBUG_INFO __NOINIT_ATTR static re_restart_debug_t _debug_info; #endif // CONFIG_RESTART_DEBUG_INFO
Заполнение данных для backtrace
Как я уже упомянул выше, в ESP-IDF не предусмотрен вывод backtrace куда-либо ещё, кроме com-порта. Что ж, придется сделать это самостоятельно. Для этого я воспользовался функцией esp_backtrace_print из файла \.platformio\packages\framework-espidf\components\xtensa\debug_helpers.c, и написал похожий вариант:
#if CONFIG_RESTART_DEBUG_INFO && (CONFIG_RESTART_DEBUG_STACK_DEPTH > 0) #include "esp_types.h" #include "esp_attr.h" #include "esp_err.h" #include "esp_debug_helpers.h" #include "soc/soc_memory_layout.h" #include "soc/cpu.h" #endif // CONFIG_RESTART_STACK_DEPTH #if CONFIG_RESTART_DEBUG_INFO void IRAM_ATTR debugHeapUpdate() { _debug_info.heap_total = heap_caps_get_total_size(MALLOC_CAP_DEFAULT); _debug_info.heap_free = heap_caps_get_free_size(MALLOC_CAP_DEFAULT); size_t _new_free_min = heap_caps_get_minimum_free_size(MALLOC_CAP_DEFAULT); if ((_debug_info.heap_free_min == 0) || (_new_free_min < _debug_info.heap_free_min)) { _debug_info.heap_free_min = _new_free_min; _debug_info.heap_min_time = time(nullptr); }; } #if CONFIG_RESTART_DEBUG_STACK_DEPTH > 0 void IRAM_ATTR debugBacktraceUpdate() { esp_backtrace_frame_t stk_frame; esp_backtrace_get_start(&(stk_frame.pc), &(stk_frame.sp), &(stk_frame.next_pc)); _debug_info.backtrace[0] = esp_cpu_process_stack_pc(stk_frame.pc); bool corrupted = (esp_stack_ptr_is_sane(stk_frame.sp) && esp_ptr_executable((void*)esp_cpu_process_stack_pc(stk_frame.pc))) ? false : true; #if CONFIG_RESTART_DEBUG_STACK_DEPTH > 1 uint8_t i = CONFIG_RESTART_DEBUG_STACK_DEPTH; while (i-- > 0 && stk_frame.next_pc != 0 && !corrupted) { if (!esp_backtrace_get_next_frame(&stk_frame)) { corrupted = true; }; _debug_info.backtrace[CONFIG_RESTART_DEBUG_STACK_DEPTH - i] = esp_cpu_process_stack_pc(stk_frame.pc); }; #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH > 1 } #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH void IRAM_ATTR debugUpdate() { debugHeapUpdate(); #if CONFIG_RESTART_DEBUG_STACK_DEPTH > 0 debugBacktraceUpdate(); #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH } #endif // CONFIG_RESTART_DEBUG_INFO
Для сохранения отладочной информации теперь достаточно вызывать debugUpdate(). При сохранении данных stk_frame.sp не сохраняется, так как это особо не влияет на расшифровку адресов. Осталось обеспечить вызов этой функции перед перезагрузкой и в случае паники.
Сохранение backtrace перед перезагрузкой устройства
Реализовать сохранение данных при “штатной” перезагрузке устройства командой esp_restart очень просто. Для этого достаточно зарегистрировать обработчик “штатной” перезагрузки. Всего можно использовать от 1 до 5 обработчиков, и это число, увы, изменить нельзя.
#if CONFIG_RESTART_DEBUG_INFO esp_register_shutdown_handler(debugUpdate); #endif // CONFIG_RESTART_DEBUG_INFO
Это обеспечит сохранение отладочной информации в зарезервированной области памяти при перезагрузке из-за обновления OTA или в других “нормальных” ситуациях. Но, увы, при “панике” из-за ошибке метод не сработает. Решить эту задачу для ESP-IDF можно, создав wrapper для системной функции esp_panic_handler с помощью опции -Wl. Для этого создаем обертку для esp_panic_handler:
// This function will be considered the esp_panic_handler to call in case a panic occurs void __wrap_esp_panic_handler(void* info) { #if CONFIG_RESTART_DEBUG_INFO && (CONFIG_RESTART_DEBUG_STACK_DEPTH > 0) debugBacktraceUpdate(); #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH // Call the original panic handler function to finish processing this error (creating a core dump for example...) __real_esp_panic_handler(info); }
Затем в файл CMakeLists.txt необходимо добавить строку idf_build_set_property(LINK_OPTIONS “-Wl,–wrap=esp_panic_handler” APPEND):
cmake_minimum_required(VERSION 3.16.0) include($ENV{IDF_PATH}/tools/cmake/project.cmake) idf_build_set_property(LINK_OPTIONS "-Wl,--wrap=esp_panic_handler" APPEND) project(village_garage)
Это заставит компилятор вызвать нашу функцию esp_panic_handler вместо “штатной”, а затем уже наша функция вызовет встроенную. Вуаля!
Отправка backtrace после перезагрузки устройства
Осталось только отправить эти данные после перезагрузки куда-нибудь на сервер. Например это можно сделать, опубликовав эти данные на mqtt-брокер. А можно отправить в telegram, добавив backtrace к информации о запуске устройства
re_restart_debug_t debugGet() { re_restart_debug_t ret; memset(&ret, 0, sizeof(re_restart_debug_t)); esp_reset_reason_t esp_reason = esp_reset_reason(); if ((esp_reason != ESP_RST_UNKNOWN) && (esp_reason != ESP_RST_POWERON)) { ret = _debug_info; if (_debug_info.heap_total > heap_caps_get_total_size(MALLOC_CAP_DEFAULT)) { memset(&ret, 0, sizeof(re_restart_debug_t)); }; }; memset(&_debug_info, 0, sizeof(re_restart_debug_t)); return ret; }
#define CONFIG_MESSAGE_TG_VERSION_DEF "🔸 Устройство запущено\n\nВерсия прошивки:
%s\nПричина перезапуска:
%s\nCPU0:
%s\nCPU1:
%s" #define CONFIG_MESSAGE_TG_VERSION_HEAP "🔸 Устройство запущено\n\nВерсия прошивки:
%s\nПричина перезапуска:
%s\nCPU0:
%s\nCPU1:
%s\nHEAP:
%s" #define CONFIG_MESSAGE_TG_VERSION_TRACE "🔸 Устройство запущено\n\nВерсия прошивки:
%s\nПричина перезапуска:
%s\nCPU0:
%s\nCPU1:
%s\nHEAP:
%s\nTRACE:
%s" #if CONFIG_RESTART_DEBUG_INFO re_restart_debug_t debug = debugGet(); char* debug_heap = statesGetDebugHeap(&debug); char* debug_trace = nullptr; if (debug_heap) { #if CONFIG_RESTART_DEBUG_STACK_DEPTH > 0 debug_trace = statesGetDebugTrace(&debug); #endif // CONFIG_RESTART_DEBUG_STACK_DEPTH if (debug_trace) { tgSend(TG_MAIN, false, CONFIG_TELEGRAM_DEVICE, CONFIG_MESSAGE_TG_VERSION_TRACE, APP_VERSION, getResetReason(), getResetReasonRtc(0), getResetReasonRtc(1), debug_heap, debug_trace); free(debug_trace); } else { tgSend(TG_MAIN, false, CONFIG_TELEGRAM_DEVICE, CONFIG_MESSAGE_TG_VERSION_HEAP, APP_VERSION, getResetReason(), getResetReasonRtc(0), getResetReasonRtc(1), debug_heap); }; free(debug_heap); } else { tgSend(TG_MAIN, false, CONFIG_TELEGRAM_DEVICE, CONFIG_MESSAGE_TG_VERSION_DEF, APP_VERSION, getResetReason(), getResetReasonRtc(0), getResetReasonRtc(1)); }; #else tgSend(TG_MAIN, false, CONFIG_TELEGRAM_DEVICE, CONFIG_MESSAGE_TG_VERSION_DEF, APP_VERSION, getResetReason(), getResetReasonRtc(0), getResetReasonRtc(1)); #endif // CONFIG_RESTART_DEBUG_INFO
Заливаем прошивку в устройство. Теперь при “программной перезагрузке” или сбое получим примерно такое сообщение:
🔸 Устройство запущено Версия прошивки: 20220320.039 Причина перезапуска: EXCEPTION / PANIC CPU0: Software reset CPU CPU1: Software reset CPU HEAP: 272800 : 104648 (38.4%) : 57644 (21.1%) 21.03.2022 07:30:00 TRACE: 0x400d39bf 0x40089792 0x40089855 0x40082d16 0x400014fa 0x4014fb51 0x40156bde 0x40156c1a 0x400d34e3 0x400da8b0 0x400d44b1 0x400dbb23
Теперь можно скопировать эти данные в attr2line и расшифровать место возникновения ошибки. Задача решена.