diff --git a/libraries/esp8266/examples/HwdtStackDump/HwdtStackDump.ino b/libraries/esp8266/examples/HwdtStackDump/HwdtStackDump.ino index ff1c41e93b..667d137881 100644 --- a/libraries/esp8266/examples/HwdtStackDump/HwdtStackDump.ino +++ b/libraries/esp8266/examples/HwdtStackDump/HwdtStackDump.ino @@ -13,6 +13,9 @@ To demonstrate this tool, this Sketch offers a few options for crashing the ESP8266 with and without a HWDT reset. + Supplimental - How to get an idea of where the sketch was last executing at + the time of the WDT. For this, review ReadMe.md in this example directory. + */ #include diff --git a/libraries/esp8266/examples/HwdtStackDump/ReadMe.md b/libraries/esp8266/examples/HwdtStackDump/ReadMe.md new file mode 100644 index 0000000000..a9666f6507 --- /dev/null +++ b/libraries/esp8266/examples/HwdtStackDump/ReadMe.md @@ -0,0 +1,61 @@ +# WIP + +# Missing Dependency +A general way of specifying build options for a sketch. There are other active PRs pursuing this effort. This PR needs to be held back and updated after one of those is finalized. For testing this PR, a limited method for the Arduino IDE/Linux OS environment is provided. + +# Watch Dog Tracks +## An Overview +A problem with both Hardware WDT and Soft WDT resets, there is no indication of where the processor is stuck. + +This solution uses the [GCC Program Instrumentation Options'](https://gcc.gnu.org/onlinedocs/gcc/Instrumentation-Options.html) "instrument-functions" to call our tracking functions to capture the most recent functions called. It stores the last caller, callee, and Stack Pointer at each function entry and exit. + +Files needed: +* `build_opt.txt` - compiler "instrument-functions" options file in the sketch folder +* `platform.local.txt` - (temporary) causes the compiler to use the sketch's `build_opt.txt` file +* `WDTracks.cpp` - Add to the sketch folder. Handles tracking and printing/reporting. + +## Implementation +The overhead is very high with this option. The functions `__cyg_profile_func_enter` and `__cyg_profile_func_exit` are used to track execution. Every function entry and exit is instrumented by the compiler with a call to the respective tracking function. This increases code size and execution time. To reduce overhead, there are three ways to specify the code to exclude from the instrumentation: build options `-finstrument-functions-exclude-function-list=...` and `-finstrument-functions-exclude-file-list=...`; and function attribute `__attribute__((no_instrument_function))`. Note, if we limit the coverage too much, we may miss the event that caused the WDT. For an idea of sketch code size increase, a sketch with a code size of 520973 bytes, grew to 803566 bytes when recompiled with the instrument-functions options shown below. + +Both `-finstrument-functions-exclude-function-list=...` and `-finstrument-functions-exclude-file-list=...` exclude when an item in the list matches as a substring in the actual symbol name or file name, respectively. This feature implementation can easily capture and exclude more functions than you intended. A challenge with this approach is the overhead and tuning the excludes, to reduce overhead without losing too many of the activity tracking calls. Use and modify with caution. + +For reporting, we have two times that we can expand on the WDT reset reporting. +1) Hardware WDT - For this HWDT or HWDT_NO4KEXTRA must be enabled from the "Arduino IDE Tools->Debug Level". The newly added tracking results are printed by callback function `hwdt_pre_sdk_init`. This call is made early during the startup process before any substantial initialization occurs that would overwrite interesting information. Care still has to be taken to exclude functions from calling "instrument-functions" at startup leading up to the call to `hwdt_pre_sdk_init`. Otherwise, our tacking information will be lost. +2) Soft WDT - this occurs during postmortem report when `custom_crash_callback` is called. If you already have a `custom_crash_callback` you will need to disable it for this debugging session. + +Both of these callback functions are predefined as _weak_ allowing for simple override replacements without the need for registration calls. + +After a WDT reset, a fake stack dump identifyed as `ctx: WDTracks` is generated. Copy-paste that block into the Exception Decoder for a backtrace of the functions called. + +## Files Needed +### `build_opt.txt` +Minimum suggested contents for file, `build_opt.txt`, (build options) to use the "-finstrument-functions" option. +``` +-finstrument-functions +-finstrument-functions-exclude-function-list=app_entry,stack_thunk_get_,ets_intr_,ets_post,Cache_Read_Enable,non32xfer_exception_handler +-finstrument-functions-exclude-file-list=umm_malloc,hwdt_app_entry,core_esp8266_postmortem,core_esp8266_app_entry_noextra4k +``` +Additional exclusions may be needed when using functions that have critical code timing loops, like I2C or high-priority interrupt routines, etc. + + + +### `platform.local.txt` +Various efforts are already under development for specifying build options for a sketch in an IDE and OS flexible manner. +For now, under Arduino IDE and Linux OS, I have been using a `platform.local.txt` file with these lines to utilize my sketch `build_opt.txt` file. +``` +custom.flags_txt.source.pathname={build.source.path}/build_opt.txt +custom.flags_txt.build.pathname={build.path}/build_opt.txt +compiler.c.extra_flags=-include "{custom.flags_txt.build.pathname}.h" @{custom.flags_txt.build.pathname} +compiler.cpp.extra_flags=-include "{custom.flags_txt.build.pathname}.h" @{custom.flags_txt.build.pathname} + +recipe.hooks.prebuild.1.pattern=mkdir -p "{build.path}/custom" +recipe.hooks.prebuild.2.pattern=bash -c "if [ -f {custom.flags_txt.source.pathname} ]; then if [ {custom.flags_txt.source.pathname} -nt {custom.flags_txt.build.pathname} ]; then cp -u {custom.flags_txt.source.pathname} {custom.flags_txt.build.pathname}; touch {custom.flags_txt.build.pathname}.h; fi; fi;" +recipe.hooks.prebuild.3.pattern=bash -c "if [ ! -f {custom.flags_txt.source.pathname} ]; then if [ -s {custom.flags_txt.build.pathname} ]; then rm {custom.flags_txt.build.pathname}; touch {custom.flags_txt.build.pathname} {custom.flags_txt.build.pathname}.h; fi; fi;" +recipe.hooks.prebuild.4.pattern=bash -c "if [ ! -f {custom.flags_txt.build.pathname} ]; then touch -t 170001010000 {custom.flags_txt.build.pathname}; fi;" +recipe.hooks.prebuild.5.pattern=bash -c "if [ ! -f {custom.flags_txt.build.pathname}.h ]; then touch -t 170001010000 {custom.flags_txt.build.pathname}.h; fi;" +``` + +### `WDTracks.cpp` +Copy `WDTracks.cpp` from this example to your sketch folder. + +Change the value of kMaxTracks to control the number of track marks saved. diff --git a/libraries/esp8266/examples/HwdtStackDump/WDTracks.cpp b/libraries/esp8266/examples/HwdtStackDump/WDTracks.cpp new file mode 100644 index 0000000000..a9bfd79150 --- /dev/null +++ b/libraries/esp8266/examples/HwdtStackDump/WDTracks.cpp @@ -0,0 +1,213 @@ +/* + For details about the GCC command line option "-finstrument-functions" see + https://gcc.gnu.org/onlinedocs/gcc/Instrumentation-Options.html + + This option allows us to track what our sketch was last doing before a crash + with Hard or Soft WDT. To do this we define functions that get called for each + function entry and exit. + + The overhead is very high with this option. So we do not want it applied + everywhere. At the same time if we limit the coverage too much, we may miss + the event that caused the WDT. + + To a build_opt.txt file in your sketch directory add the following build options: + -finstrument-functions + -finstrument-functions-exclude-function-list=app_entry,stack_thunk_get_,ets_intr_,ets_post,Cache_Read_Enable,non32xfer_exception_handler + -finstrument-functions-exclude-file-list=umm_malloc,hwdt_app_entry,core_esp8266_postmortem,core_esp8266_app_entry_noextra4k + + Various efforts are under devlopment to handle build options for a sketch. + For now to use your build_opt.txt file, create a platform.local.txt file with + these lines: + custom.flags_txt.source.pathname={build.source.path}/build_opt.txt + custom.flags_txt.build.pathname={build.path}/build_opt.txt + compiler.c.extra_flags=-include "{custom.flags_txt.build.pathname}.h" @{custom.flags_txt.build.pathname} + + recipe.hooks.prebuild.1.pattern=mkdir -p "{build.path}/custom" + recipe.hooks.prebuild.2.pattern=bash -c "if [ -f {custom.flags_txt.source.pathname} ]; then if [ {custom.flags_txt.source.pathname} -nt {custom.flags_txt.build.pathname} ]; then cp -u {custom.flags_txt.source.pathname} {custom.flags_txt.build.pathname}; touch {custom.flags_txt.build.pathname}.h; fi; fi;" + recipe.hooks.prebuild.3.pattern=bash -c "if [ ! -f {custom.flags_txt.source.pathname} ]; then if [ -s {custom.flags_txt.build.pathname} ]; then rm {custom.flags_txt.build.pathname}; touch {custom.flags_txt.build.pathname} {custom.flags_txt.build.pathname}.h; fi; fi;" + recipe.hooks.prebuild.4.pattern=bash -c "if [ ! -f {custom.flags_txt.build.pathname} ]; then touch -t 170001010000 {custom.flags_txt.build.pathname}; fi;" + recipe.hooks.prebuild.5.pattern=bash -c "if [ ! -f {custom.flags_txt.build.pathname}.h ]; then touch -t 170001010000 {custom.flags_txt.build.pathname}.h; fi;" + +*/ +#include +#include +#include + +#ifndef ALWAYS_INLINE +#define ALWAYS_INLINE inline __attribute__((always_inline)) +#endif + +extern "C" { + + constexpr size_t kMaxTracks = 32; // Change to control the number of track marks saved. + + struct WDTrackMark { + void *this_fn; // The starting address if the function called + void *call_site; // On return, the next address to execute in callee function. + void *sp; // SP for "this_fn" not that of "call_site" (callee) + bool enter; // True when recording a __cyg_profile_func_enter call + // False when recording a __cyg_profile_func_exit call + }; + struct WDTracksCBuf { + size_t idx; + struct WDTrackMark tracks[kMaxTracks]; + }; + /* + If you need to debug a WDT that occurs before user_init() is called to + perform "C"/"C++" runtime initialization, then add + "__attribute__((section(".noinit")))" to wd_tracks and do ets_memset from + hwdt_pre_sdk_init as shown below. And, build with "Debug Level: HWDT". + Otherwise, the data captured in wd_tracks starts after user_init(). + */ + struct WDTracksCBuf wd_tracks; + + IRAM_ATTR void __cyg_profile_func_enter(void *this_fn, void *call_site) __attribute__((no_instrument_function)); + IRAM_ATTR void __cyg_profile_func_exit(void *this_fn, void *call_site) __attribute__((no_instrument_function)); + void print_wdtracks(void) __attribute__((no_instrument_function)); + + void custom_crash_callback(struct rst_info * rst_info, uint32_t stack, uint32_t stack_end) __attribute__((no_instrument_function)); + + /* + Printing from hwdt_pre_sdk_init() requires special considerations. Normal + "C" runtime initialization has not run at the time it is called. For + printing from this context, we use umm_info_safe_printf_P. It is capable + of handling this situation and is a function included in umm_malloc. + */ + int umm_info_safe_printf_P(const char *fmt, ...); +#define ETS_PRINTF(fmt, ...) umm_info_safe_printf_P(PSTR(fmt), ##__VA_ARGS__) +#define ETS_PRINTF_P(fmt, ...) umm_info_safe_printf_P(fmt, ##__VA_ARGS__) + +#if defined(DEBUG_ESP_HWDT) || defined(DEBUG_ESP_HWDT_NOEXTRA4K) + void hwdt_pre_sdk_init(void) __attribute__((no_instrument_function)); + + // Called from HWDT just before starting SDK + // Serial speed has been initialized for us. + void hwdt_pre_sdk_init(void) { + if (REASON_WDT_RST == hwdt_info.reset_reason) { + /* + Note, we rely on the previous values of the wd_tracks structure, still + set from before the crash. At the time we are called here, the SDK has + not started. The "C" runtime code that will zero the structure does not + run until later when the SDK calls user_init(). + */ + print_wdtracks(); + } + /* + You can skip direct initialization of wd_tracks without causing crashes. + After kMaxTracks calls, all uninitialized data is overwritten. In most + user-based WDT crashes, you can assume that a sufficient number + (kMaxTracks) of calls will fill the circular buffer before a crash + occurs. + */ + ets_memset(&wd_tracks, 0, sizeof(wd_tracks)); + } +#endif + + // Called from Postmortem + void custom_crash_callback(struct rst_info * rst_info, uint32_t stack, uint32_t stack_end) + { + (void)stack; + (void)stack_end; + if (REASON_SOFT_WDT_RST == rst_info->reason) { + print_wdtracks(); + } + } + /* + Functions __cyg_profile_func_enter and __cyg_profile_func_exit are + identical except for the "bool enter" value. These are very high call + frequency functions. Avoid using a common function to save code space. By + forcing inline, we avoid the time to creating a new stack frame and the + register save event for making a call. + Side note, needed to keep __attribute__((no_instrument_function)); on + forced inline parts otherwise the resulting ASM was strange and larger. + */ + static ALWAYS_INLINE void __cyg_profile_func(void *this_fn, void *call_site, bool enter) __attribute__((no_instrument_function)); + void __cyg_profile_func(void *this_fn, void *call_site, bool enter) + { + uint32_t saved_ps = xt_rsil(15); + + size_t idx = wd_tracks.idx; + // Doing range check here makes an uninitialized structure safe! + if (kMaxTracks <= idx) { + idx = 0; + } + + struct WDTrackMark *track = &wd_tracks.tracks[idx]; + /* + Extended ASM note, If "track" is an input register the compiler assumes + it has been overwriten by the ASM code and recalculates its prior value. + As an output read/write register the compiler skips the recalculation. + This saved two bytes. At this time, with GCC-10.2.0, the resulting code + generated by this Extended ASM, integrated into the "C" code ASM in an + optimum way. + */ + asm volatile ( + "s32i a1, %[track], %[track_sp]\n\t" + : [track]"+a"(track) + : [track_sp]"I"(offsetof(struct WDTrackMark, sp)) + :); + track->this_fn = this_fn; // The address of the function called + track->call_site = call_site; // The saved return address "a0" of the callee + track->enter = enter; + wd_tracks.idx = ++idx; + + xt_wsr_ps(saved_ps); + } + + /* + Called at function entry after stackframe setup and registers are saved. + */ + void __cyg_profile_func_enter(void *this_fn, void *call_site) + { + __cyg_profile_func(this_fn, call_site, true); + } + + + /* + Called at function exit just before saved registers and stackframe are + restored. + */ + void __cyg_profile_func_exit(void *this_fn, void *call_site) + { + __cyg_profile_func(this_fn, call_site, false); + } + + void print_wdtracks(void) + { + /* + Print as a fake stack dump with our WDTrack info so that the ESP Exception + Decoder will assist with a call trace printout by putting source code + location to the addresses presented in the stack dump. + + It is assumed we are called from a context that interrupts will not occur. + Also, all function called from here must not be "instrumented" + */ + size_t idx = wd_tracks.idx; + idx--; + if (kMaxTracks <= idx) { + idx = kMaxTracks - 1; + } + struct WDTrackMark *track = &wd_tracks.tracks[idx]; + ETS_PRINTF("\nepc1=%p\n", track->this_fn); + + uintptr_t fake_start = (uintptr_t)0x3FFFE000; // Arbitrary value - using ending address of SYS stack space. + uintptr_t fake_end = fake_start + (uintptr_t)(kMaxTracks * sizeof(struct WDTrackMark)); + ETS_PRINTF("\n>>>stack>>>\n\nctx: WDTracks\n"); + ETS_PRINTF("sp: %08x end: %08x offset: 0000\n", fake_start, fake_end); + + // Print most recent first to stay consistent with how the stack dump/decode + // would normally appear. + for (size_t i = 0; i < kMaxTracks; i++) { + ETS_PRINTF("%08x: %08x %08x %08x %08x\n", fake_start + i * 0x10u, + track->this_fn, track->enter, track->sp, track->call_site); + idx--; + if (kMaxTracks <= idx) { + idx = kMaxTracks - 1; + } + track = &wd_tracks.tracks[idx]; + } + + ETS_PRINTF("<<