diff --git a/app/debug_stream_overlay.conf b/app/debug_stream_overlay.conf index cd310b9a7fa8..7edd6bf6709c 100644 --- a/app/debug_stream_overlay.conf +++ b/app/debug_stream_overlay.conf @@ -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 diff --git a/src/debug/debug_stream/Kconfig b/src/debug/debug_stream/Kconfig index 8756c83ef8da..6e831ae7a7aa 100644 --- a/src/debug/debug_stream/Kconfig +++ b/src/debug/debug_stream/Kconfig @@ -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. + config SOF_DEBUG_STREAM_TEXT_MSG bool "Enable text message sending through Debug-Stream" help @@ -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 diff --git a/src/debug/debug_stream/debug_stream_slot.c b/src/debug/debug_stream/debug_stream_slot.c index a55c1c1e116d..341fbdebc279 100644 --- a/src/debug/debug_stream/debug_stream_slot.c +++ b/src/debug/debug_stream/debug_stream_slot.c @@ -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; @@ -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); @@ -116,18 +122,18 @@ 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(); + unsigned int max_num_cpus = CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS; size_t hdr_size = ALIGN_UP(offsetof(struct debug_stream_slot_hdr, - section_desc[CONFIG_MP_MAX_NUM_CPUS]), + section_desc[max_num_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, + size_t section_size = ALIGN_DOWN(section_area_size / max_num_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, + max_num_cpus, section_size, hdr_size, section_area_size); #ifdef CONFIG_INTEL_ADSP_DEBUG_SLOT_MANAGER @@ -142,9 +148,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 + max_num_cpus * section_size; + hdr->num_sections = max_num_cpus; + for (i = 0; i < max_num_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]))/ @@ -154,7 +160,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 < max_num_cpus; i++) { struct debug_stream_section_descriptor desc = { 0 }; struct debug_stream_circular_buf *buf = debug_stream_get_circular_buffer(&desc, i); diff --git a/src/debug/debug_stream/debug_stream_text_msg.c b/src/debug/debug_stream/debug_stream_text_msg.c index 4ee71322a3e0..97c209d42c94 100644 --- a/src/debug/debug_stream/debug_stream_text_msg.c +++ b/src/debug/debug_stream/debug_stream_text_msg.c @@ -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; @@ -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 @@ -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]; 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) @@ -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; @@ -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; } @@ -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 diff --git a/src/include/user/debug_stream_text_msg.h b/src/include/user/debug_stream_text_msg.h index 3d246e305fc3..debfaad7042e 100644 --- a/src/include/user/debug_stream_text_msg.h +++ b/src/include/user/debug_stream_text_msg.h @@ -7,6 +7,7 @@ #define __SOC_DEBUG_STREAM_TEXT_MSG_H__ #include +#include /* * Debug Stream text message. @@ -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__ */