Skip to content

Exception dump hook #10517

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
jsarha wants to merge 5 commits into
base: main
Choose a base branch
from
+105 −13
Open

Exception dump hook #10517

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
ba001a4
debug: debug_stream_slot: Use spinlock instead of mutex for ISR
Feb 2, 2026
7fb5898
debug_stream: text_msg: Set exception dump hooks if available
Feb 2, 2026
bbc7cd5
debug_stream: text_msg: exception: Skip useless " ** " prefix
Feb 10, 2026
7832931
tools: debug_stream.py: Cut text msg when first '\0' is encountered
Mar 3, 2026
ded889b
app: debug_stream_overlay.conf: Enable exception hook
Mar 3, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions app/debug_stream_overlay.conf
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,8 @@ CONFIG_SOF_DEBUG_STREAM_TEXT_MSG=y
CONFIG_SOF_DEBUG_STREAM_THREAD_INFO=y
# Zephyr option for storing human readable thread names
CONFIG_THREAD_NAME=y
# For Zephyr to compile with thread names on PTL we need to increase THREAD_BYTES
CONFIG_MAX_THREAD_BYTES=4

# Debug window slot configuration 1
# The CONFIG_SOF_TELEMETRY uses slot 2, but with performance and IO-performance
Expand All @@ -20,3 +22,9 @@ CONFIG_SOF_TELEMETRY_IO_PERFORMANCE_MEASUREMENTS=n
#CONFIG_SOF_TELEMETRY_PERFORMANCE_MEASUREMENTS=n
#CONFIG_SOF_TELEMETRY_IO_PERFORMANCE_MEASUREMENTS=n

# Enable Zephyr exception printing hook, debug stream is sensitive to this option too
CONFIG_EXCEPTION_DUMP_HOOK=y
# Do not try to sen the exception prints through logs, this causes probles on PTL with mtrace
Copy link

Copilot AI Mar 3, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Typo in comment: "sen" → "send".

Suggested change
# Do not try to sen the exception prints through logs, this causes probles on PTL with mtrace
# Do not try to send the exception prints through logs, this causes problems on PTL with mtrace

Copilot uses AI. Check for mistakes.
Copy link

Copilot AI Mar 3, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Typo in comment: "probles" → "problems".

Suggested change
# Do not try to sen the exception prints through logs, this causes probles on PTL with mtrace
# Do not try to sen the exception prints through logs, this causes problems on PTL with mtrace

Copilot uses AI. Check for mistakes.
CONFIG_EXCEPTION_DUMP_HOOK_ONLY=y
# Print also backtrace through the exception hook
CONFIG_XTENSA_BACKTRACE_EXCEPTION_DUMP_HOOK=y
16 changes: 5 additions & 11 deletions src/debug/debug_stream/debug_stream_slot.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,11 +10,12 @@
#include <rtos/string.h>
#include <user/debug_stream.h>
#include <user/debug_stream_slot.h>
#include <zephyr/kernel.h>

LOG_MODULE_REGISTER(debug_stream_slot);

struct cpu_mutex {
struct k_mutex m;
struct k_spinlock l;
} __aligned(CONFIG_DCACHE_LINE_SIZE);

/* CPU specific mutexes for each circular buffer */
Expand Down Expand Up @@ -66,6 +67,7 @@ int debug_stream_slot_send_record(struct debug_stream_record *rec)
debug_stream_get_circular_buffer(&desc, arch_proc_id());
uint32_t record_size = rec->size_words;
uint32_t record_start, buf_remain;
k_spinlock_key_t key;

LOG_DBG("Sending record %u id %u len %u", rec->seqno, rec->id, rec->size_words);

Expand All @@ -77,7 +79,7 @@ int debug_stream_slot_send_record(struct debug_stream_record *rec)
desc.buf_words, desc.core_id, desc.buf_words, desc.offset);
return -ENOMEM;
}
k_mutex_lock(&cpu_mutex[arch_proc_id()].m, K_FOREVER);
key = k_spin_lock(&cpu_mutex[arch_proc_id()].l);

rec->seqno = buf->next_seqno++;
rec->size_words = record_size + 1; /* +1 for size at the end of record */
Expand Down Expand Up @@ -105,7 +107,7 @@ int debug_stream_slot_send_record(struct debug_stream_record *rec)
buf->data[buf->w_ptr] = record_size + 1;
buf->w_ptr = (buf->w_ptr + 1) % desc.buf_words;

k_mutex_unlock(&cpu_mutex[arch_proc_id()].m);
k_spin_unlock(&cpu_mutex[arch_proc_id()].l, key);

LOG_DBG("Record %u id %u len %u sent", rec->seqno, rec->id, record_size);
return 0;
Expand Down Expand Up @@ -159,14 +161,6 @@ static int debug_stream_slot_init(void)

buf->next_seqno = 0;
buf->w_ptr = 0;
k_mutex_init(&cpu_mutex[i].m);
/* The core specific mutexes are now .bss which is uncached so the
* following line is commented out. However, since the mutexes are
* core specific there should be nothing preventing from having them
* in cached memory.
*
* sys_cache_data_flush_range(&cpu_mutex[i], sizeof(cpu_mutex[i]));
*/
}
LOG_INF("Debug stream slot initialized");

Expand Down
89 changes: 89 additions & 0 deletions src/debug/debug_stream/debug_stream_text_msg.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,9 +8,13 @@
#include <soc.h>
#include <adsp_debug_window.h>
#include <sof/common.h>
#include <zephyr/logging/log.h>
#include <zephyr/arch/exception.h>

#include <user/debug_stream_text_msg.h>

LOG_MODULE_REGISTER(debug_stream_text_msg);

void ds_msg(const char *format, ...)
{
va_list args;
Expand All @@ -33,3 +37,88 @@ void ds_msg(const char *format, ...)
sizeof(buf.msg.hdr.data[0]));
debug_stream_slot_send_record(&buf.msg.hdr);
}

#if defined(CONFIG_EXCEPTION_DUMP_HOOK)
/* The debug stream debug window slot is 4k, and when it is split
* between the cores and the header/other overhead is removed, with 5
* cores the size is 768 bytes. The dump record must be smaller than
* that to get through to the host side.
*
* Also, because of the limited circular buffer size, we should only
* send one exception record. Exceptions often happen in bursts in a
* SOF system, and sending more than one record makes the host-side
* decoder lose track of things.
*/
static struct {
struct debug_stream_text_msg msg;
char text[640];
} __packed ds_buf;
Comment on lines +52 to +55
Copy link

Copilot AI Mar 3, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ds_buf is declared __packed, which drops its alignment to 1. Because ds_buf.msg.hdr contains 32-bit fields that are accessed directly and passed to debug_stream_slot_send_record(), this can lead to unaligned accesses if the linker places ds_buf at a byte-aligned address. Consider removing __packed here and/or forcing at least 4-byte alignment for ds_buf.

Suggested change
static struct {
struct debug_stream_text_msg msg;
char text[640];
} __packed ds_buf;
static _Alignas(4) struct {
struct debug_stream_text_msg msg;
char text[640];
} ds_buf;

Copilot uses AI. Check for mistakes.
static int reports_sent_cpu[CONFIG_MP_MAX_NUM_CPUS];
static size_t ds_pos;
Comment on lines +52 to +57
Copy link

Copilot AI Mar 3, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ds_buf and ds_pos are global across all CPUs, but reports_sent_cpu[] is per-CPU. If two cores hit an exception around the same time, both can write into the same ds_buf.text/ds_pos concurrently before reports_sent_cpu[arch_proc_id()] is incremented in ds_exception_drain(), producing a data race and corrupted/merged dumps. Make the buffer/position per-CPU (e.g., arrays indexed by arch_proc_id()) or protect updates with a lock that is safe in exception context.

Copilot uses AI. Check for mistakes.

static void ds_exception_drain(bool flush)
{
if (flush) {
ds_pos = 0;
return;
}

if (reports_sent_cpu[arch_proc_id()]++ > 0)
return;

ds_buf.msg.hdr.id = DEBUG_STREAM_RECORD_ID_TEXT_MSG;
ds_buf.msg.hdr.size_words = SOF_DIV_ROUND_UP(sizeof(ds_buf.msg) + ds_pos,
sizeof(ds_buf.msg.hdr.data[0]));
/* Make sure the possible upto 3 extra bytes at end of msg are '\0' */
memset(ds_buf.text + ds_pos, 0, ds_buf.msg.hdr.size_words *
sizeof(ds_buf.msg.hdr.data[0]) - ds_pos);
debug_stream_slot_send_record(&ds_buf.msg.hdr);
ds_pos = 0;
}

static void ds_exception_dump(const char *format, va_list args)
{
ssize_t len;
size_t avail;
size_t written;

if (reports_sent_cpu[arch_proc_id()] > 0)
return;

avail = sizeof(ds_buf.text) - ds_pos;
if (avail == 0) {
ds_exception_drain(false);
return;
}

/* Skip useless " ** " prefix to save bytes */
if (strlen(format) >= 4 &&
format[0] == ' ' && format[1] == '*' && format[2] == '*' && format[3] == ' ')
format += 4;

len = vsnprintf(ds_buf.text + ds_pos, avail, format, args);
if (len < 0) {
ds_pos = 0;
return;
}

if ((size_t)len >= avail)
written = avail - 1;
else
written = (size_t)len;

ds_pos += written;

if (ds_pos >= sizeof(ds_buf.text))
ds_exception_drain(false);
}

static int init_exception_dump_hook(void)
{
set_exception_dump_hook(ds_exception_dump, ds_exception_drain);
LOG_INF("exception_dump_hook set");
return 0;
}

SYS_INIT(init_exception_dump_hook, APPLICATION, CONFIG_KERNEL_INIT_PRIORITY_DEFAULT);
#endif
5 changes: 3 additions & 2 deletions tools/debug_stream/debug_stream.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -162,8 +162,9 @@ def print_text_msg(self, record, cpu):
buffer = (
ctypes.c_ubyte * (len(record) - ctypes.sizeof(TextMsg))
).from_address(ctypes.addressof(record) + ctypes.sizeof(TextMsg))
msg = bytearray(buffer).decode("utf-8")
print("CPU %u: %s" % (cpu, msg))
payload = bytes(buffer)
msg = payload.split(b"\0", 1)[0].decode("utf-8", errors="replace")
print("CPU %u:\n%s" % (cpu, msg))
return True

class DebugStreamSectionDescriptor(ctypes.Structure):
Expand Down
Loading