From a03e5386dc49f824264c86a4a27a6d398c505d04 Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Fri, 16 Jul 2021 09:25:23 +0000 Subject: [PATCH] trace: add _log_nodict() and enable DMA trace for Zephyr As of July 2021 we support (too) many tracing options and this duplication is unfortunately the only way I found to support them all while giving the compiler the opportunity to optimize away as many strings as possible. Supported configurations: - Systems with limited memory and zero space for full strings, must use SOF dictionary only. - Systems with enough space for all strings to be in memory. - Anything in between - Support to duplicate only important message to both the DMA and the mailbox (the default) - CONFIG_TRACEM: supports duplicating ALL messages to both the DMA and the mailbox - CONFIG_TRACEV: supports deleting verbose statements at compile time to save space - CONFIG_TRACE: support turning off all traces at compile-time - SOF dict trace de-duplication a.k.a. "adaptive filtering" - Dynamic log levels per component - Redirection to Zephyr's shared memory tracing that requires full strings. Signed-off-by: Marc Herbert --- src/include/sof/trace/trace.h | 25 ++++++++++++++++++++++++- src/trace/trace.c | 5 +++++ zephyr/include/sof/trace/trace.h | 20 +++++--------------- 3 files changed, 34 insertions(+), 16 deletions(-) diff --git a/src/include/sof/trace/trace.h b/src/include/sof/trace/trace.h index e518986d9..92463d69d 100644 --- a/src/include/sof/trace/trace.h +++ b/src/include/sof/trace/trace.h @@ -206,7 +206,14 @@ void mtrace_event(const char *complete_packet, uint32_t length); } #ifdef CONFIG_TRACEM /* Send everything to shared memory too */ -# define MTRACE_DUPLICATION_LEVEL LOG_LEVEL_DEBUG +# ifdef __ZEPHYR__ +/* We don't use Zephyr's dictionary yet so there's not enough space for + * DEBUG messages + */ +# define MTRACE_DUPLICATION_LEVEL LOG_LEVEL_INFO +# else +# define MTRACE_DUPLICATION_LEVEL LOG_LEVEL_DEBUG +# endif #else /* copy only ERRORS */ # define MTRACE_DUPLICATION_LEVEL LOG_LEVEL_ERROR #endif /* CONFIG_TRACEM */ @@ -269,8 +276,24 @@ do { \ ); \ _log_sofdict(log_func, atomic, &log_entry, ctx, lvl, id_1, id_2, \ META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__), ##__VA_ARGS__); \ + _log_nodict(atomic, META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__), \ + lvl, format, ##__VA_ARGS__); \ } while (0) +#ifdef __ZEPHYR__ +/* Just like XTOS, only the most urgent messages go to limited + * shared memory. + */ +#define _log_nodict(atomic, arg_count, lvl, format, ...) \ +do { \ + if ((lvl) <= MTRACE_DUPLICATION_LEVEL) \ + printk("%llu " format "\n", platform_timer_get(NULL), \ + ##__VA_ARGS__); \ +} while (0) +#else +#define _log_nodict(atomic, n_args, lvl, format, ...) +#endif + #endif /* CONFIG_LIBRARY */ #else /* CONFIG_TRACE */ diff --git a/src/trace/trace.c b/src/trace/trace.c index 4cdb11cd9..f311d6021 100644 --- a/src/trace/trace.c +++ b/src/trace/trace.c @@ -92,6 +92,7 @@ static void put_header(void *dst, const struct sof_uuid_entry *uid, } +#ifndef __ZEPHYR__ /** Ring buffer for the mailbox trace */ void mtrace_event(const char *data, uint32_t length) { @@ -110,6 +111,7 @@ void mtrace_event(const char *data, uint32_t length) dcache_writeback_region(t + trace->pos, length); trace->pos += length; } +#endif /* __ZEPHYR__ */ #if CONFIG_TRACE_FILTERING_VERBOSITY /** @@ -548,11 +550,14 @@ void _log_sofdict(log_func_t sofdict_logf, bool atomic, const void *log_entry, { va_list ap; +#ifndef __ZEPHYR__ /* for Zephyr see _log_nodict() in trace.h */ if (lvl <= MTRACE_DUPLICATION_LEVEL) { va_start(ap, arg_count); mtrace_dict_entry_vl(atomic, (uint32_t)log_entry, arg_count, ap); va_end(ap); } +#endif + va_start(ap, arg_count); sofdict_logf(atomic, log_entry, ctx, lvl, id_1, id_2, arg_count, ap); va_end(ap); diff --git a/zephyr/include/sof/trace/trace.h b/zephyr/include/sof/trace/trace.h index 7d24708c8..64888cff2 100644 --- a/zephyr/include/sof/trace/trace.h +++ b/zephyr/include/sof/trace/trace.h @@ -25,10 +25,10 @@ struct timer; uint64_t platform_timer_get(struct timer *timer); /* - * Override SOF dictionary macros for now and let Zephyr take care of - * the physical log IO. + * Override SOF mtrace_printf() macro for now to support Zephyr's shared + * memory logger. Note the DMA trace can be copied to the shared memory + * too thanks to CONFIG_TRACEM. */ -#undef _log_message #undef mtrace_printf #if USE_PRINTK @@ -38,18 +38,8 @@ uint64_t platform_timer_get(struct timer *timer); printk("%llu: " format "\n", platform_timer_get(NULL), \ ##__VA_ARGS__); \ } while (0) -#define _log_message(log_func, atomic, level, comp_class, ctx, id1, id2, format, ...) \ - do { \ - if ((level) <= SOF_ZEPHYR_TRACE_LEVEL) \ - printk("%llu: " format "\n", platform_timer_get(NULL), \ - ##__VA_ARGS__); \ - } while (0) -#else /* not tested */ -#define _log_message(log_func, atomic, level, comp_class, ctx, id1, id2, format, ...) \ - do { \ - Z_LOG(level, "%u: " format, (uint32_t)platform_timer_get(NULL), \ - ##__VA_ARGS__); \ - } while (0) +#else +#error "TODO: Z_LOG()" #endif #endif /* __INCLUDE_TRACE__ */