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 839ba4b6f215..6ac6280c611c 100644 --- a/src/debug/debug_stream/Kconfig +++ b/src/debug/debug_stream/Kconfig @@ -54,6 +54,17 @@ config SOF_DEBUG_STREAM_THREAD_INFO_TOTAL_CPU_LOAD_TO_LOG print the total CPU load (sum of all threads) to the logging system. +config SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS + int "Number of cpu sections slot is divided to" + default CORE_COUNT + 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 @@ -63,4 +74,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 d75c8248a45c..82816a6788f3 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,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 @@ -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])) / @@ -153,7 +160,7 @@ static int debug_stream_slot_init(void) LOG_DBG("sections %u, size %u, offset %u", 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); diff --git a/src/debug/debug_stream/debug_stream_text_msg.c b/src/debug/debug_stream/debug_stream_text_msg.c index 8bb3925a1550..97db0fd29330 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,48 @@ 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(). Static data is + * currently placed in .bss and its ATM uncached so the ds_cpu table + * elements do not need to be cache aligned, but if this changes we + * need __aligned(CONFIG_DCACHE_LINE_SIZE) here. + */ +static struct ds_cpu_state { + struct { + struct debug_stream_text_msg msg; + char text[640]; + } __packed buf; + int reports_sent; + size_t pos; +} ds_cpu[CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_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 +105,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 +124,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,9 +138,9 @@ 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); } @@ -136,4 +152,32 @@ static int init_exception_dump_hook(void) } 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/debug/debug_stream/debug_stream_thread_info.c b/src/debug/debug_stream/debug_stream_thread_info.c index 5564c0d2dbb4..5e00b697caa9 100644 --- a/src/debug/debug_stream/debug_stream_thread_info.c +++ b/src/debug/debug_stream/debug_stream_thread_info.c @@ -22,6 +22,9 @@ LOG_MODULE_REGISTER(thread_info); /* Data structure to store the cycle counter values from the previous * round. The numbers are used to calculate what the load was on this * round. + * Static data is currently placed in .bss and its ATM uncached so the + * ds_cpu table elements do not need to be cache aligned, but if this + * changes we need __aligned(CONFIG_DCACHE_LINE_SIZE) here. */ static struct previous_counters { /* Cached data from previous round */ uint64_t active; /* All execution cycles */ @@ -30,7 +33,7 @@ static struct previous_counters { /* Cached data from previous round */ void *tid; /* thread ID (the thread struct ptr) */ uint64_t cycles; /* cycle counter value */ } threads[THREAD_INFO_MAX_THREADS]; /* The max amount of threads we follow */ -} __aligned(CONFIG_DCACHE_LINE_SIZE) previous[CONFIG_MP_MAX_NUM_CPUS]; +} previous[CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS]; #endif /* @@ -341,9 +344,10 @@ static void thread_info_run(void *cnum, void *a, void *b) } #define THREAD_STACK_SIZE (2048) -static K_THREAD_STACK_ARRAY_DEFINE(info_thread_stacks, CONFIG_MP_MAX_NUM_CPUS, +static K_THREAD_STACK_ARRAY_DEFINE(info_thread_stacks, + CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS, THREAD_STACK_SIZE); -static struct k_thread info_thread[CONFIG_MP_MAX_NUM_CPUS]; +static struct k_thread info_thread[CONFIG_SOF_DEBUG_STREAM_SLOT_FORCE_MAX_CPUS]; static int thread_info_start(void) { 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__ */