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 <[email protected]>

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,7 +276,23 @@ 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 */
 

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);

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__ */