From c4254bafbfb0dc84ba99d5d784f060088e0c7ac8 Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Fri, 2 Feb 2024 21:42:29 +0000 Subject: [PATCH] arch/posix.h: implement ARCH_EXCEPT() with abort() for debug convenience Flush all messages and invoke `abort()` when a k_panic() or k_oops() is hit in native_posix mode. One of the main purposes of `native_posix` is to provide debug convenience. When running in a debugger, `abort()` stops execution which provides a backtrace and the ability to inspect all variables. A practical use case is fuzzing failures in SOF, see an example in: https://github.com/thesofproject/sof/pull/8632 In such a case, this commit adds value even before using a debugger. Without this commit, confusingly meaningless stack trace: ``` INFO: seed corpus: files: 1097 min: 1b max: 428b total: 90853b rss: 58Mb Exiting due to fatal error ==314134== ERROR: libFuzzer: fuzz target exited #0 0x81d9637 in __sanitizer_print_stack_trace (zephyr.exe+0x81d9637) #1 0x80cc42b in fuzzer::PrintStackTrace() (zephyr.exe+0x80cc42b) #2 0x80ab79e in fuzzer::Fuzzer::ExitCallback() FuzzerLoop.cpp.o #3 0x80ab864 in fuzzer::Fuzzer::StaticExitCallback() (zephyr.exe+ #4 0xf783dfe8 (/usr/lib32/libc.so.6+0x3dfe8) #5 0xf783e1e6 in exit (/usr/lib32/libc.so.6+0x3e1e6) #6 0x82a5488 in posix_exit boards/posix/native_posix/main.c:51:2 SUMMARY: libFuzzer: fuzz target exited ``` Thanks to this commit the `k_panic()` location is immediately available in the logs without even running anything: ``` INFO: seed corpus: files: 1097 min: 1b max: 428b total: 90853b rss: 58Mb ==315176== ERROR: libFuzzer: deadly signal LLVMSymbolizer: error reading file: No such file or directory #0 0x81d9647 in __sanitizer_print_stack_trace (zephyr.exe+0x81d9647) #1 0x80cc43b in fuzzer::PrintStackTrace() (zephyr.exe+0x80cc43b) #2 0x80ab6be in fuzzer::Fuzzer::CrashCallback() FuzzerLoop.cpp.o #3 0x80ab77b in fuzzer::Fuzzer::StaticCrashSignalCallback() #4 0xf7f3159f (linux-gate.so.1+0x59f) #5 0xf7f31578 (linux-gate.so.1+0x578) #6 0xf788ea16 (/usr/lib32/libc.so.6+0x8ea16) #7 0xf783b316 in raise (/usr/lib32/libc.so.6+0x3b316) #8 0xf7822120 in abort (/usr/lib32/libc.so.6+0x22120) #9 0x82afbde in ipc_cmd src/ipc/ipc3/handler.c:1623:2 NOTE: libFuzzer has rudimentary signal handlers. Combine libFuzzer with AddressSanitizer or similar for better crash reports. SUMMARY: libFuzzer: deadly signal ``` Full stack trace When running zephyr.exe in gdb: ``` ./scripts/fuzz.sh -- -DEXTRA_CFLAGS="-O0 -g3" gdb ./zephyr.exe backtrace #2 0xf783b317 in raise () from /usr/lib32/libc.so.6 #3 0xf7822121 in abort () from /usr/lib32/libc.so.6 #4 0x082afbdf in ipc_cmd (_hdr=0x8b...) at src/ipc/ipc3/handler.c:1623 #5 0x082fbf4b in ipc_platform_do_cmd (ipc=0x8b161c0) at src/platform/posix/ipc.c:162 #6 0x082e1e07 in ipc_do_cmd (data=0x8b161c0 ) at src/ipc/ipc-common.c:328 #7 0x083696aa in task_run (task=0x8b161e8 ) at zephyr/include/rtos/task.h:94 #8 0x083682dc in edf_work_handler (work=0x8b1621c ) at zephyr/edf_schedule.c:32 #9 0x085245af in work_queue_main (workq_ptr=0x8b15b00 ,...) at zephyr/kernel/work.c:688 #10 0x0823a6bc in z_thread_entry (entry=0x8523be0 ,.. at zephyr/lib/os/thread_entry.c:48 #11 0x0829a6a1 in posix_arch_thread_entry (pa_thread_status=0x8630648 .. at zephyr/arch/posix/core/thread.c:56 #12 0x0829c043 in posix_thread_starter (arg=0x4) at zephyr/arch/posix/core/posix_core.c:293 #13 0x080f6041 in asan_thread_start(void*) () #14 0xf788c73c in ?? () from /usr/lib32/libc.so.6 ``` Signed-off-by: Marc Herbert --- include/zephyr/arch/posix/arch.h | 43 ++++++++++++++++++++++++++++++++ 1 file changed, 43 insertions(+) diff --git a/include/zephyr/arch/posix/arch.h b/include/zephyr/arch/posix/arch.h index 83aceb1c14ba1f..3c4b7150d031f5 100644 --- a/include/zephyr/arch/posix/arch.h +++ b/include/zephyr/arch/posix/arch.h @@ -17,6 +17,8 @@ #ifndef ZEPHYR_INCLUDE_ARCH_POSIX_ARCH_H_ #define ZEPHYR_INCLUDE_ARCH_POSIX_ARCH_H_ +#include + /* Add include for DTS generated information */ #include @@ -38,6 +40,47 @@ extern "C" { #define ARCH_STACK_PTR_ALIGN 4 #endif +/* "native_posix" should really use CONFIG_LOG_MODE_IMMEDIATE=y but better safe + * than sorry: debugging crashes is painful enough already, so try to be nice + * and flush all messages. The deferred logging code may also want to enjoy + * native_posix too. + * + * Other archs use Zephyr's elaborate "Fatal Errors" framework which takes care + * of flushing logs but native_posix is simpler so we have to do it ourselves. + */ +static inline void posix_arch_log_immediate(void) +{ +#if defined(CONFIG_LOG) && !defined(CONFIG_LOG_MODE_MINIMAL) + /* We can't #include the higher-level "log_ctrl.h" in this low-level + * file here because this descends into .h dependency hell. So let's + * use a one-line forward declaration instead. This void->void + * prototype does not look like it's going to change much in the + * future. + * + * We can't declare "void log_panic(void);" because it is not what it + * seems but a complicated static inline + macro override in + * generated/syscalls/log_ctrl.h. In native_posix mode log_panic() + * boils down to just z_impl_log_panic() so exceptionally invoke that + * directly. + */ + void z_impl_log_panic(void); + z_impl_log_panic(); +#endif +} + +/* Invoked by k_panic() and k_oops(). + * + * ZTEST triggers some panics on purpose: don't interfere. + */ +#ifndef CONFIG_ZTEST +#define ARCH_EXCEPT(reason_p) do { \ + posix_arch_log_immediate(); \ + printk("ARCH_EXCEPT reason: %u\n", reason_p); \ + abort(); CODE_UNREACHABLE; \ +} while (false) +#endif + +/* Exception context */ struct __esf { uint32_t dummy; /*maybe we will want to add something someday*/ };