From 0eac9e2d0a7c490c22f04677eaa38b2923d843fe 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 good, sample 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 now immediately available in test logs without even running anything locally: ``` INFO: seed corpus: files: 1097 min: 1b max: 428b total: 90853b rss: 58Mb @ WEST_TOPDIR/sof/src/ipc/ipc3/handler.c:1623 ZEPHYR FATAL ERROR: 3 ==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 ``` The full stack trace is now immediately available when running zephyr.exe in gdb: ``` ./scripts/fuzz.sh -- -DEXTRA_CFLAGS="-O0 -g3" gdb build-fuzz/zephyr/zephyr.exe run 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 | 49 +++++++++++++++++++++++++++++++ lib/libc/common/CMakeLists.txt | 8 +++++ tests/lib/c_lib/common/src/main.c | 3 +- 3 files changed, 59 insertions(+), 1 deletion(-) diff --git a/include/zephyr/arch/posix/arch.h b/include/zephyr/arch/posix/arch.h index 83aceb1c14ba..79e83bd9d928 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,53 @@ 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 just declare "void log_panic(void);" here because system + * calls are complicated. As ARCH_EXCEPT() can't be possibly used in + * user mode, log_panic() is equivalent to just z_impl_log_panic(). + * Exceptionally invoke the latter directly. + */ + extern void z_impl_log_panic(void); + z_impl_log_panic(); +#endif +} + +/* Copied from kernel.h */ +#define _EXCEPT_LOC() __ASSERT_PRINT("@ %s:%d\n", __FILE__, __LINE__) + +/* Invoked by k_panic() and k_oops(). + * + * _EXCEPT_LOC() and "ZEPHYR FATAL ERROR" mimic z_fatal_error() + * + * Many [Z]TESTs invoke k_panic(). The test framework expects that to + * hang forever like hardware does; so don't exit / don't interfere. + */ +#if !defined(CONFIG_ZTEST) && !defined(CONFIG_TEST) +#define ARCH_EXCEPT(reason_p) do { \ + posix_arch_log_immediate(); \ + _EXCEPT_LOC(); \ + printk("ZEPHYR FATAL ERROR: %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*/ }; diff --git a/lib/libc/common/CMakeLists.txt b/lib/libc/common/CMakeLists.txt index 4b101d8b84bd..a34bec493101 100644 --- a/lib/libc/common/CMakeLists.txt +++ b/lib/libc/common/CMakeLists.txt @@ -4,10 +4,18 @@ zephyr_system_include_directories(include) zephyr_library() zephyr_library_property(ALLOW_EMPTY TRUE) + +# This abort.c is only a shim for k_panic(), which in posix/arch.h ends +# up calling... abort()! Break that cycle and use the real POSIX +# abort(). +if(NOT CONFIG_ARCH_POSIX) zephyr_library_sources_ifdef(CONFIG_COMMON_LIBC_ABORT source/stdlib/abort.c) +endif() + zephyr_library_sources_ifdef(CONFIG_COMMON_LIBC_TIME source/time/time.c) zephyr_library_sources_ifdef(CONFIG_COMMON_LIBC_MALLOC source/stdlib/malloc.c) zephyr_library_sources_ifdef(CONFIG_COMMON_LIBC_STRNLEN source/string/strnlen.c) + zephyr_library_sources_ifdef(CONFIG_COMMON_LIBC_THRD source/thrd/cnd.c source/thrd/mtx.c diff --git a/tests/lib/c_lib/common/src/main.c b/tests/lib/c_lib/common/src/main.c index 986dba55f8e9..3d2ffeb70cab 100644 --- a/tests/lib/c_lib/common/src/main.c +++ b/tests/lib/c_lib/common/src/main.c @@ -1220,7 +1220,8 @@ ZTEST(libc_common, test_rand_reproducibility) */ ZTEST(libc_common, test_abort) { -#ifdef CONFIG_EXTERNAL_LIBC +/* posix/arch.h uses a real abort() too */ +#if defined(CONFIG_EXTERNAL_LIBC) || defined(CONFIG_ARCH_POSIX) ztest_test_skip(); #else int a = 0;