Skip to content

Exception dump update #10654

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 6 commits into
base: main
Choose a base branch
from
+123 −40
Open

Exception dump update #10654

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
a3c44b3
debug_stream: text_msg: Align to latest changes to Zephyr PR changes
Mar 17, 2026
f2388f1
debug_stream: text_msg: collect per-CPU state into cacheline-aligned …
Mar 26, 2026
8b8450f
debug_stream: text_msg: Add CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS
Mar 19, 2026
cd33717
debug_stream: text_msg: add va_list-based logging helper
Mar 12, 2026
0a3e1fb
debug_stream: text_msg: add optional assert_print() forwarding
Mar 17, 2026
ae17802
app: debug_stream_overlay.conf: Add new debug_stream Kconfig options
Mar 25, 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
11 changes: 11 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 @@ -8,6 +8,17 @@ CONFIG_SOF_DEBUG_STREAM_THREAD_INFO=y
CONFIG_THREAD_NAME=y
# For Zephyr to compile with thread names on PTL we need to increase THREAD_BYTES
CONFIG_MAX_THREAD_BYTES=4
# Shrink number of CPU sections
# As the number of supported cores shrink, the available circular
# buffer size increases. This means increased bandwidth. This is
# particularly useful, when debugging a problem on core 0.
#CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS=1

# Direct the assert prints to debug stream
# This option obeys CONFIG_EXCEPTION_DUMP_HOOK_ONLY. If it is selected
# the assert print is sent only to debug stream. Without it the assert
# prints are printed with vprintk too,
CONFIG_SOF_DEBUG_STREAM_TEXT_MSG_ASSERT_PRINT=y

# Debug window slot configuration 1
# The CONFIG_SOF_TELEMETRY uses slot 2, but with performance and IO-performance
Expand Down
21 changes: 21 additions & 0 deletions src/debug/debug_stream/Kconfig
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,17 @@ config SOF_DEBUG_STREAM_THREAD_INFO_INTERVAL
Decides how often thread info runs and checks execution cycle
statistics and stack usage.

config SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS
int "Number of cpu sections slot is divided to"
default MP_MAX_NUM_CPUS
range 1 MP_MAX_NUM_CPUS
help
In some situations a high number of cpu sections shrinks the
circular buffer size so much that it limit debugging. With
this option its possible to use fewer sections. The downside
is that the cpus above the number of sections can not send
any debug stream messages.
Copy link
Collaborator

@lyakh lyakh Mar 26, 2026

Choose a reason for hiding this comment

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

can this be done at run-time? If yes, you could use a CPU-mask here instead. Where static arrays are allocated, allocate CONFIG_CORE_COUNT of them, but at run-time count bits in the mask and divide the window in as many sections?

Copy link
Contributor Author

@jsarha jsarha Mar 26, 2026 •
edited
Loading

Choose a reason for hiding this comment

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

Everything is possible, but the amount of refactoring needed is IMO not at all proportional to the benefit. The original design principle was to initialize everything at boot time, and then be a totally passive and light weight system to pass debug information from DSP to the host. Nor is this feature enabled by default, there is not even debug slots available for it unless some other features are turned off, which makes runtime configuration quite useless. One anyway needs to rebuild the FW to use this feature.

Run time reconfiguration would require almost complete rewrite of both the FW side implementation and the host side decoding and invention of new APIs on how to change the configuration at runtime.

The CPU mask style stuff would be slightly more feasible, but I do not see any significant benefit over this low hanging fruit. In 90% of cases one wants to debug core 0 incidents, and the remaining 10% fall to three first cores (ATM our topologies do not utilize more than 3 cores). So most of the time setting this value to 1 or 3 is enough. And if one wants to test some multicore case with max debug_stream bandwidth he/she can make a custom topology for the case to fit the event to as low number of cores as possible.


config SOF_DEBUG_STREAM_TEXT_MSG
bool "Enable text message sending through Debug-Stream"
help
Expand All @@ -54,4 +65,14 @@ config SOF_DEBUG_STREAM_TEXT_MSG
ds_msg(). See include/user/debug_stream_text_msg.h for
prototype.

config SOF_DEBUG_STREAM_TEXT_MSG_ASSERT_PRINT
bool "Enable assert print sending through Debug-Stream"
depends on EXCEPTION_DUMP_HOOK && (ASSERT || ASSERT_VERBOSE)
select SOF_DEBUG_STREAM_TEXT_MSG
help
Enable assert print sending over debug stream as text
message. This feature is also sensitive to Zephyr option
CONFIG_EXCEPTION_DUMP_HOOK_ONLY. If that is set then the
asserts are not printed through printk interface.

endif
27 changes: 17 additions & 10 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 @@ -19,7 +19,7 @@ struct cpu_mutex {
} __aligned(CONFIG_DCACHE_LINE_SIZE);

/* CPU specific mutexes for each circular buffer */
static struct cpu_mutex cpu_mutex[CONFIG_MP_MAX_NUM_CPUS];
static struct cpu_mutex cpu_mutex[CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS];

#ifdef CONFIG_INTEL_ADSP_DEBUG_SLOT_MANAGER
static struct debug_stream_slot_hdr *dbg_stream_slot;
Expand Down Expand Up @@ -54,6 +54,12 @@ debug_stream_get_circular_buffer(struct debug_stream_section_descriptor *desc, u
return NULL;
}

if (core >= CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS) {
LOG_DBG("No section for cpu %u >= %u ", core,
CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS);
return NULL;
}

*desc = hdr->section_desc[core];
LOG_DBG("Section %u (desc %u %u %u)", core, desc->core_id, desc->buf_words, desc->offset);

Expand Down Expand Up @@ -116,18 +122,19 @@ int debug_stream_slot_send_record(struct debug_stream_record *rec)
static int debug_stream_slot_init(void)
{
struct debug_stream_slot_hdr *hdr = debug_stream_get_slot();
size_t hdr_size = ALIGN_UP(offsetof(struct debug_stream_slot_hdr,
section_desc[CONFIG_MP_MAX_NUM_CPUS]),
CONFIG_DCACHE_LINE_SIZE);
size_t hdr_size = ALIGN_UP(
offsetof(struct debug_stream_slot_hdr,
section_desc[CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS]),
CONFIG_DCACHE_LINE_SIZE);
size_t section_area_size = ADSP_DW_SLOT_SIZE - hdr_size;
size_t section_size = ALIGN_DOWN(section_area_size /
CONFIG_MP_MAX_NUM_CPUS,
CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS,
CONFIG_DCACHE_LINE_SIZE);
size_t offset = hdr_size;
int i;

LOG_INF("%u sections of %u bytes, hdr %u, section area %u",
CONFIG_MP_MAX_NUM_CPUS, section_size, hdr_size,
CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS, section_size, hdr_size,
section_area_size);

#ifdef CONFIG_INTEL_ADSP_DEBUG_SLOT_MANAGER
Expand All @@ -142,9 +149,9 @@ static int debug_stream_slot_init(void)

hdr->hdr.magic = DEBUG_STREAM_IDENTIFIER;
hdr->hdr.hdr_size = hdr_size;
hdr->total_size = hdr_size + CONFIG_MP_MAX_NUM_CPUS * section_size;
hdr->num_sections = CONFIG_MP_MAX_NUM_CPUS;
for (i = 0; i < CONFIG_MP_MAX_NUM_CPUS; i++) {
hdr->total_size = hdr_size + CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS * section_size;
hdr->num_sections = CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS;
for (i = 0; i < CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS; i++) {
hdr->section_desc[i].core_id = i;
hdr->section_desc[i].buf_words =
(section_size - offsetof(struct debug_stream_circular_buf, data[0]))/
Expand All @@ -154,7 +161,7 @@ static int debug_stream_slot_init(void)
i, section_size, offset);
offset += section_size;
}
for (i = 0; i < CONFIG_MP_MAX_NUM_CPUS; i++) {
for (i = 0; i < CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS; i++) {
struct debug_stream_section_descriptor desc = { 0 };
struct debug_stream_circular_buf *buf =
debug_stream_get_circular_buffer(&desc, i);
Expand Down
102 changes: 72 additions & 30 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 @@ -15,18 +15,15 @@

LOG_MODULE_REGISTER(debug_stream_text_msg);

void ds_msg(const char *format, ...)
void ds_vamsg(const char *format, va_list args)
{
va_list args;
struct {
struct debug_stream_text_msg msg;
char text[128];
} __packed buf = { 0 };
ssize_t len;

va_start(args, format);
len = vsnprintf(buf.text, sizeof(buf.text), format, args);
va_end(args);

if (len < 0)
return;
Expand All @@ -38,6 +35,15 @@ void ds_msg(const char *format, ...)
debug_stream_slot_send_record(&buf.msg.hdr);
}

void ds_msg(const char *format, ...)
{
va_list args;

va_start(args, format);
ds_vamsg(format, args);
va_end(args);
}

#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
Expand All @@ -49,39 +55,46 @@ void ds_msg(const char *format, ...)
* in bursts, and sending more than one record in short time makes the
* host-side decoder lose track of things.
*/
static struct {
struct debug_stream_text_msg msg;
char text[640];
} __packed ds_buf[CONFIG_MP_MAX_NUM_CPUS];
static int reports_sent_cpu[CONFIG_MP_MAX_NUM_CPUS];
static size_t ds_pos[CONFIG_MP_MAX_NUM_CPUS];

/* Per-CPU state for exception dump and assert_print().
* Cache-line aligned to avoid false sharing between cores.
*/
static struct ds_cpu_state {
struct {
struct debug_stream_text_msg msg;
char text[640];
} __packed buf;
int reports_sent;
size_t pos;
} __aligned(CONFIG_DCACHE_LINE_SIZE) ds_cpu[CONFIG_MP_MAX_NUM_CPUS];
Copy link
Collaborator

@lyakh lyakh Mar 27, 2026

Choose a reason for hiding this comment

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

this is placed into .bss so it isn't cached, so no cache-line alignment should be needed?


static void ds_exception_drain(bool flush)
{
unsigned int cpu = arch_proc_id();
struct ds_cpu_state *cs = &ds_cpu[cpu];

if (flush) {
ds_pos[cpu] = 0;
reports_sent_cpu[cpu] = 0;
cs->pos = 0;
return;
}

if (ds_pos[cpu] == 0)
if (cs->pos == 0)
return;

if (reports_sent_cpu[cpu] > 0)
if (cs->reports_sent > 0)
return;

ds_buf[cpu].msg.hdr.id = DEBUG_STREAM_RECORD_ID_TEXT_MSG;
ds_buf[cpu].msg.hdr.size_words =
SOF_DIV_ROUND_UP(sizeof(ds_buf[cpu].msg) + ds_pos[cpu],
sizeof(ds_buf[cpu].msg.hdr.data[0]));
cs->buf.msg.hdr.id = DEBUG_STREAM_RECORD_ID_TEXT_MSG;
cs->buf.msg.hdr.size_words =
SOF_DIV_ROUND_UP(sizeof(cs->buf.msg) + cs->pos,
sizeof(cs->buf.msg.hdr.data[0]));

/* Make sure the possible up to 3 extra bytes at end of msg are '\0' */
memset(ds_buf[cpu].text + ds_pos[cpu], 0,
ds_buf[cpu].msg.hdr.size_words * sizeof(ds_buf[cpu].msg.hdr.data[0]) - ds_pos[cpu]);
debug_stream_slot_send_record(&ds_buf[cpu].msg.hdr);
reports_sent_cpu[cpu] = 1;
ds_pos[cpu] = 0;
memset(cs->buf.text + cs->pos, 0,
cs->buf.msg.hdr.size_words * sizeof(cs->buf.msg.hdr.data[0]) - cs->pos);
debug_stream_slot_send_record(&cs->buf.msg.hdr);
cs->reports_sent = 1;
cs->pos = 0;
}

static void ds_exception_dump(const char *format, va_list args)
Expand All @@ -90,11 +103,12 @@ static void ds_exception_dump(const char *format, va_list args)
size_t avail;
size_t written;
unsigned int cpu = arch_proc_id();
struct ds_cpu_state *cs = &ds_cpu[cpu];

if (reports_sent_cpu[cpu] > 0)
if (cs->reports_sent > 0)
return;

avail = sizeof(ds_buf[cpu].text) - ds_pos[cpu];
avail = sizeof(cs->buf.text) - cs->pos;
if (avail == 0) {
ds_exception_drain(false);
return;
Expand All @@ -108,9 +122,9 @@ static void ds_exception_dump(const char *format, va_list args)
format[0] == ' ' && format[1] == '*' && format[2] == '*' && format[3] == ' ')
format += 4;

len = vsnprintf(ds_buf[cpu].text + ds_pos[cpu], avail, format, args);
len = vsnprintf(cs->buf.text + cs->pos, avail, format, args);
if (len < 0) {
ds_pos[cpu] = 0;
cs->pos = 0;
return;
}

Expand All @@ -122,18 +136,46 @@ static void ds_exception_dump(const char *format, va_list args)
else
written = (size_t)len;

ds_pos[cpu] += written;
cs->pos += written;

if (ds_pos[cpu] >= sizeof(ds_buf[cpu].text))
if (cs->pos >= sizeof(cs->buf.text))
ds_exception_drain(false);
}

static int init_exception_dump_hook(void)
{
set_exception_dump_hook(ds_exception_dump, ds_exception_drain);
arch_exception_set_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);

#if defined(CONFIG_SOF_DEBUG_STREAM_TEXT_MSG_ASSERT_PRINT)
void assert_print(const char *fmt, ...)
{
va_list ap;

/* Do not print assert after exception has been dumped */
if (ds_cpu[arch_proc_id()].reports_sent > 0)
return;

va_start(ap, fmt);
#if !defined(CONFIG_EXCEPTION_DUMP_HOOK_ONLY)
{
va_list ap2;

va_copy(ap2, ap);
#endif
ds_vamsg(fmt, ap);
#if !defined(CONFIG_EXCEPTION_DUMP_HOOK_ONLY)
vprintk(fmt, ap2);
va_end(ap2);
}
#endif
ds_vamsg(fmt, ap);
va_end(ap);
}
EXPORT_SYMBOL(assert_print);
#endif
#endif
2 changes: 2 additions & 0 deletions src/include/user/debug_stream_text_msg.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#define __SOC_DEBUG_STREAM_TEXT_MSG_H__

#include <user/debug_stream_slot.h>
#include <stdarg.h>

/*
* Debug Stream text message.
Expand All @@ -21,5 +22,6 @@ struct debug_stream_text_msg {
* CONFIG_SOF_DEBUG_STREAM_TEXT_MSG to enable this function.
*/
void ds_msg(const char *format, ...);
void ds_vamsg(const char *format, va_list ap);

#endif /* __SOC_DEBUG_STREAM_TEXT_MSG_H__ */
Loading