[BUG] ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148

Hello, I'm writing this message after encountering a crash while performing open source fuzzing, referencing oss-fuzz.

Describe the bug
I am experiencing the following error message.

ASSERTION FAIL [!ret] @ WEST_TOPDIR/sof/src/audio/selector/selector.c:196
@ ZEPHYR_BASE/lib/os/assert.c:43
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:00:00.000,000] <err> os: Current thread: 0x8429080 (unknown)
[00:00:00.000,000] <err> zephyr: Halting system
ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148
        Attempted to recover from a kernel panic condition
@ ZEPHYR_BASE/lib/os/assert.c:43
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:00:00.000,000] <err> os: Current thread: 0x8429080 (unknown)
[00:00:00.000,000] <err> zephyr: Halting system

To Reproduce
The environment is identical to what is registered in OSS-Fuzz. Below are the entry point and input data information for the SOF fuzzer that triggers a crash.

reproduce command

python infra/helper.py build_fuzzers sound-open-firmware
python infra/helper.py shell sound-open-firemware
cd /out
./sof-ipc3 [crash_data_path]

LLVMFuzzerTestOneInput in /src/sof/zephyr/boards/posix/native_posix/main.c

uint8_t *posix_fuzz_buf, posix_fuzz_sz;

int LLVMFuzzerTestOneInput(const uint8_t *data, size_t sz)
{
	static bool posix_initialized;

	if (!posix_initialized) {
		posix_init(0, NULL);
		posix_initialized = true;
	}

	/* Provide the fuzz data to Zephyr as an interrupt, with
	 * "DMA-like" data placed into posix_fuzz_buf/sz
	 */
	posix_fuzz_buf = (void *)data;
	posix_fuzz_sz = sz;
	hw_irq_ctrl_set_irq(CONFIG_ARCH_POSIX_FUZZ_IRQ);

	/* Give the OS time to process whatever happened in that
	 * interrupt and reach an idle state.
	 */
	posix_exec_for(k_ticks_to_us_ceil64(CONFIG_ARCH_POSIX_FUZZ_TICKS));

	return 0;
}

input data(hex)

00 26 41 FF FF 33 00 FF 00 01 00 00 00 00 FF FB E8 00 00 00 00 09 00 00 00 00 00 00 CA 00 FF 02 E5 00 00 00 00 00 26 2A FF 01 00 00 00 00 00 45 FF 60 00 00 00 02 FF 84 FF 00 00 41 00 00 00 00 00 00 00 92 22 00 08 06 95 06 00 FF 00 10 00 00 00 26 41 FF FF A1 2B 0A 01 30 36 00 FF FF 11 00 00 00 00 00 03 18 00 00 00 00 00 00 00 00 24 00 00 00 03 18 F9 27 C8 A1 2B 0A 01 30 33 00 FF 00 01 00 00 00 00 FF FB E8 00 00 00 00 09 00 00 00 00 00 00 CA 00 FF 02 E5 00 00 00 00 00 26 2A FF 01 00 00 00 00 00 45 FF 60 00 00 00 02 FF 84 FF 00 00 41 00 00 00 00 00 00 00 92 22 00 08 06 95 06 00 FF 00 10 00 00 00 26 41 FF FF A1 2B 0A 01 30 36 00 FF FF 10 00 00 00 00 00 03 18 00 00 00 00 00 00 00 00 24 00 00 00 03 18 F9 27 C8 4E 83 51 C7

Reproduction Rate
All the time in my experience

Expected behavior
The Address Sanitizer has detected a stack overflow

Impact
Not processing

Environment
This has been reproduced on both Zephyr SDK 0.16.1 and Zephyr SDK 0.16.2-rc1.
(This implies that it was also reproduced in the 8038fa commit version of the SOF project.)

Screenshots or console output

[00:00:00.000,000] <err> zephyr: Halting system
ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148
        Attempted to recover from a kernel panic condition
@ ZEPHYR_BASE/lib/os/assert.c:43
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:00:00.000,000] <err> os: Current thread: 0x8429080 (unknown)
[00:00:00.000,000] <err> zephyr: Halting system
ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148
        Attempted to recover from a kernel panic condition
@ ZEPHYR_BASE/lib/os/assert.c:43
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:00:00.000,000] <err> os: Current thread: 0x8429080 (unknown)
AddressSanitizer:DEADLYSIGNAL
=================================================================
==544675==ERROR: AddressSanitizer: stack-overflow on address 0xef6fdffc (pc 0xf7c479d1 bp 0xf7df1a60 sp 0xef6fe000 T7)
    #0 0xf7c479d1 in _IO_file_overflow libio/./libio/fileops.c:731:1
    #1 0xf7c46b7f in _IO_new_file_xsputn libio/./libio/fileops.c:1243:11
    #2 0xf7c46b7f in _IO_file_xsputn libio/./libio/fileops.c:1196:1
    #3 0xf7c31b19 in outstring_func stdio-common/./stdio-common/vfprintf-internal.c:239:16
    #4 0xf7c31b19 in __vfprintf_internal stdio-common/./stdio-common/vfprintf-internal.c:1593:7
    #5 0xf7c1af69 in _IO_vfprintf stdio-common/./stdio-common/vfprintf.c:23:10
    #6 0x80f05fb in vfprintf /src/llvm-project/compiler-rt/lib/asan/../sanitizer_common/sanitizer_common_interceptors.inc:1661:1
    #7 0x81c3a14 in posix_print_trace /src/sof/zephyr/boards/posix/native_posix/tracing.c:43:2

SUMMARY: AddressSanitizer: stack-overflow libio/./libio/fileops.c:731:1 in _IO_file_overflow
Thread T7 created by T3 here:
    #0 0x813a23c in pthread_create /src/llvm-project/compiler-rt/lib/asan/asan_interceptors.cpp:208:3
    #1 0x81bdda7 in posix_new_thread /src/sof/zephyr/arch/posix/core/posix_core.c:380:2
    #2 0x81beebe in arch_new_thread /src/sof/zephyr/arch/posix/core/thread.c:50:2
    #3 0x82ae187 in z_setup_new_thread /src/sof/zephyr/kernel/thread.c:566:2
    #4 0x82ae782 in z_impl_k_thread_create /src/sof/zephyr/kernel/thread.c:654:2
    #5 0x82b3aa3 in k_thread_create /src/sof/sof/build/zephyr/include/generated/syscalls/kernel.h:50:9
    #6 0x82b3aa3 in k_work_queue_start /src/sof/zephyr/kernel/work.c:733:8
    #7 0x81f79a6 in scheduler_init_edf /src/sof/sof/zephyr/edf_schedule.c:106:2
    #8 0x81cdfe7 in platform_init /src/sof/sof/src/platform/posix/posix.c:77:2
    #9 0x81f4f02 in primary_core_init /src/sof/sof/src/init/init.c:287:6
    #10 0x82ad3c8 in z_sys_init_run_level /src/sof/zephyr/kernel/init.c:281:10
    #11 0x82ad3c8 in bg_thread_main /src/sof/zephyr/kernel/init.c:311:2
    #12 0x8193c32 in z_thread_entry /src/sof/zephyr/lib/os/thread_entry.c:36:2
    #13 0x815f639 in __asan::AsanThread::ThreadStart(unsigned long long) /src/llvm-project/compiler-rt/lib/asan/asan_thread.cpp:277:25

Thread T3 created by T2 here:
    #0 0x813a23c in pthread_create /src/llvm-project/compiler-rt/lib/asan/asan_interceptors.cpp:208:3
    #1 0x81bdda7 in posix_new_thread /src/sof/zephyr/arch/posix/core/posix_core.c:380:2
    #2 0x81beebe in arch_new_thread /src/sof/zephyr/arch/posix/core/thread.c:50:2
    #3 0x82ae187 in z_setup_new_thread /src/sof/zephyr/kernel/thread.c:566:2
    #4 0x82ad23a in prepare_multithreading /src/sof/zephyr/kernel/init.c:432:14
    #5 0x82accaa in z_cstart /src/sof/zephyr/kernel/init.c:558:24
    #6 0x81bf5ad in zephyr_wrapper /src/sof/zephyr/soc/posix/inf_clock/soc.c:188:2

Thread T2 created by T0 here:
    #0 0x813a23c in pthread_create /src/llvm-project/compiler-rt/lib/asan/asan_interceptors.cpp:208:3
    #1 0x81bf3e9 in posix_boot_cpu /src/sof/zephyr/soc/posix/inf_clock/soc.c:209:2
    #2 0x81c3550 in posix_init /src/sof/zephyr/boards/posix/native_posix/main.c:80:2
    #3 0x81c3550 in LLVMFuzzerTestOneInput /src/sof/zephyr/boards/posix/native_posix/main.c:137:3
    #4 0x8090f2e in fuzzer::Fuzzer::ExecuteCallback(unsigned char const*, unsigned int) /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerLoop.cpp:611:15
    #5 0x807c18e in fuzzer::RunOneTest(fuzzer::Fuzzer*, char const*, unsigned int) /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerDriver.cpp:324:6
    #6 0x8081d90 in fuzzer::FuzzerDriver(int*, char***, int (*)(unsigned char const*, unsigned int)) /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerDriver.cpp:860:9
    #7 0x80aa717 in main /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerMain.cpp:20:10
    #8 0xf7bea518 in __libc_start_call_main csu/../sysdeps/nptl/libc_start_call_main.h:58:16

==544675==ABORTING

This has been reproduced on both Zephyr SDK 0.16.1 and Zephyr SDK 0.16.2-rc1.
(This implies that it was also reproduced in the 8038fa commit version of the SOF project.)

Thanks for the report but please provide complete reproduction steps with the exact commits used to reproduce; especially if you strayed away from the canonical sof/west.yml. This should be short, just make sure you start for a totally clean workspace.

Please also share the approximate fuzzing duration required (without any prior corpus).

python infra/helper.py build_fuzzers sound-open-firmware
python infra/helper.py shell sound-open-firemware
cd /out
./sof-ipc3 [crash_data_path]

I have no idea what these are. Please reproduce with open-source code only, this is the open-source tracker.

I've seen this one appear in the cloud logs. Unfortunately there's not much to be said here speficially. What's happening is that this is a recursive panic (zephyr has a double fault framework, but it's only present when userspace is enabled, which doesn't exist with any of the SOF architectures). The panic context on the interrupt stack is itself panicing, etc... Eventually that shows up as a stack overflow to the fuzz layer. But the original error condition doesn't seem to leave any trace.

The commit ID you reference is a tiny bit stale. Can you try a commit after #7756 merged, which contains some fuzz-detected fixes and if nothing else might clean up your error flow?

The commit ID you reference is a tiny bit stale. Can you try a commit after #7756 merged, which contains some fuzz-detected fixes and if nothing else might clean up your error flow?

Thank you for your response.

After changing to the commit(#7756) version you suggested and proceeding with the reproduction, the recursive error has been resolved.

INFO: Running with entropic power schedule (0xFF, 100).
INFO: Seed: 669246699
INFO: Loaded 1 modules   (11386 inline 8-bit counters): 11386 [0x837e28b, 0x8380f05), 
INFO: Loaded 1 PC tables (11386 PCs): 11386 [0x8380f08,0x83972d8), 
./sof-ipc3: Running 1 inputs 1 time(s) each.
Running: ./sof-ipc3_poc/sound-open-firmware--sof-ipc3--crash-2e4b4d5af06c2217f12141eee8c48af2-2023-05-30-20:37:09
*** Booting Zephyr OS build v3.4.0-rc2 ***
[00:00:00.000,000] <inf> main: SOF on native_posix
[00:00:00.000,000] <inf> main: SOF initialized
ASSERTION FAIL [!ret] @ WEST_TOPDIR/sof/src/audio/selector/selector.c:196
@ ZEPHYR_BASE/lib/os/assert.c:43
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:00:00.000,000] <err> os: Current thread: 0x842a600 (unknown)
[00:00:00.000,000] <err> zephyr: Halting system
Exiting due to fatal error
==20016== ERROR: libFuzzer: fuzz target exited
    #0 0x815b8d2 in __sanitizer_print_stack_trace /src/llvm-project/compiler-rt/lib/asan/asan_stack.cpp:87:3
    #1 0x80a9ef6 in fuzzer::PrintStackTrace() /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerUtil.cpp:210:5
    #2 0x808f947 in fuzzer::Fuzzer::ExitCallback() /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerLoop.cpp:250:3
    #3 0x808f8de in fuzzer::Fuzzer::StaticExitCallback() /src/llvm-project/compiler-rt/lib/fuzzer/FuzzerLoop.cpp:209:6
    #4 0xf7c63d05  (/lib32/libc.so.6+0x33d05) (BuildId: 8c11d7b4ac6d685f0bba1cf2506a80f64d314582)
    #5 0xf7c63ee6 in exit (/lib32/libc.so.6+0x33ee6) (BuildId: 8c11d7b4ac6d685f0bba1cf2506a80f64d314582)
    #6 0x81c3599 in posix_exit /src/sof/zephyr/boards/posix/native_posix/main.c:51:2

DEDUP_TOKEN: __sanitizer_print_stack_trace--fuzzer::PrintStackTrace()--fuzzer::Fuzzer::ExitCallback()
SUMMARY: libFuzzer: fuzz target exited

Navigation Menu

Repository navigation

[BUG] ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148 #7725

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

[BUG] ASSERTION FAIL [reason != K_ERR_KERNEL_PANIC] @ ZEPHYR_BASE/kernel/fatal.c:148 #7725

Description

Activity

marc-hb commented on Jun 12, 2023

andyross commented on Jun 12, 2023

Jminis commented on Jun 12, 2023

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions