From c2511a9b2fe73dad008d85746faba293937c1920 Mon Sep 17 00:00:00 2001 From: Serhiy Katsyuba Date: Wed, 21 Oct 2026 17:18:36 +0200 Subject: [PATCH] ipc4: logging: make the mtrace hook safe in any context The mtrace log backend calls the hook with its own spinlock held, so the hook must not sleep, but a k_mutex may sleep under contention. Replace the mutex with a spinlock. Nothing done under the lock sleeps: the IPC notification and the delayed log work are only queued. On a fatal error the hook is also called from the exception handler: coredump() calls LOG_PANIC() to flush the pending logs, and it does so before k_sys_fatal_error_handler() runs, so a flag set there would be too late. Two problems showed up in this context: - k_mutex_lock() asserts in ISR context, so every DSP fatal error was hidden behind a secondary assertion. - Queueing the IPC notification or the log work takes the work queue lock, which the faulting code may hold, e.g. on an assertion in k_work_reschedule_for_queue(). The DSP then deadlocked after the first log line. Return early from the hook when k_is_in_isr() is true. The log data is already in the buffer, and the host reads the final write pointer when it receives the EXCEPTION_CAUGHT notification. Signed-off-by: Serhiy Katsyuba --- src/ipc/ipc4/logging.c | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/src/ipc/ipc4/logging.c b/src/ipc/ipc4/logging.c index af6845933688..296a57b92305 100644 --- a/src/ipc/ipc4/logging.c +++ b/src/ipc/ipc4/logging.c @@ -61,7 +61,8 @@ static uint32_t mtrace_aging_timer = IPC4_MTRACE_NOTIFY_AGING_TIMER_MS; #define MTRACE_IPC_CORE PLATFORM_PRIMARY_CORE_ID -static K_MUTEX_DEFINE(log_mutex); +/* the hook runs under the mtrace backend spinlock */ +static struct k_spinlock log_lock; static struct k_work_delayable log_work; static void mtrace_log_hook_unlocked(size_t written, size_t space_left) @@ -93,22 +94,28 @@ static void mtrace_log_hook_unlocked(size_t written, size_t space_left) static void mtrace_log_hook(size_t written, size_t space_left) { - k_mutex_lock(&log_mutex, K_FOREVER); + k_spinlock_key_t key; + + /* fatal exception log flush: IPC and work queue won't run anyway, their locks may be held */ + if (k_is_in_isr()) + return; + + key = k_spin_lock(&log_lock); mtrace_log_hook_unlocked(written, space_left); - k_mutex_unlock(&log_mutex); + k_spin_unlock(&log_lock, key); } static void log_work_handler(struct k_work *work) { - k_mutex_lock(&log_mutex, K_FOREVER); + k_spinlock_key_t key = k_spin_lock(&log_lock); if (k_uptime_get() - mtrace_notify_last_sent >= mtrace_aging_timer && mtrace_bytes_pending) mtrace_log_hook_unlocked(0, 0); - k_mutex_unlock(&log_mutex); + k_spin_unlock(&log_lock, key); } static struct k_work_sync ipc4_log_work_sync;