probe: add backend for logging via probes

src/include/ipc/probe.h

@@ -22,6 +22,8 @@
 
 #define PROBE_PURPOSE_EXTRACTION	0x1
 #define PROBE_PURPOSE_INJECTION		0x2
+#define PROBE_PURPOSE_LOGGING		0x3
+#define PROBE_PURPOSE_TRACING		0x4
 
 #define PROBE_EXTRACT_SYNC_WORD		0xBABEBEBA
 
@@ -109,7 +111,7 @@ struct probe_dma {
  */
 struct probe_point {
 	uint32_t buffer_id;	/**< ID of buffer to which probe is attached */
-	uint32_t purpose;	/**< PROBE_PURPOSE_EXTRACTION or PROBE_PURPOSE_INJECTION */
+	uint32_t purpose;	/**< PROBE_PURPOSE_xxx */
 	uint32_t stream_tag;	/**< Stream tag of DMA via which data will be provided for injection.
 				 *   For extraction purposes, stream tag is ignored when received,
 				 *   but returned actual extraction stream tag via INFO function.

src/include/kernel/abi.h

@@ -29,7 +29,7 @@
 
 /** \brief SOF ABI version major, minor and patch numbers */
 #define SOF_ABI_MAJOR 3
-#define SOF_ABI_MINOR 23
+#define SOF_ABI_MINOR 24
 #define SOF_ABI_PATCH 0
 
 /** \brief SOF ABI version number. Format within 32bit word is MMmmmppp */

src/include/sof/probe/probe.h

@@ -12,6 +12,25 @@
 
 #include <ipc/probe.h>
 
+/*
+ * Buffer id used in the probe output stream headers for
+ * logging data packet.
+ */
+#define PROBE_LOGGING_BUFFER_ID 0
+
+/**
+ * A buffer of logging data is available for processing.
+ */
+typedef void(*probe_logging_hook_t)(uint8_t *buffer, size_t length);
+
+/**
+ * @brief Initialize the probe logging backend.
+ *
+ * @param hook Function is called when new logging data is written
+ *             out by the logger.
+ */
+void probe_logging_init(probe_logging_hook_t hook);
+
 /*
  * \brief Initialize probes subsystem
  *

src/logging/Kconfig

@@ -0,0 +1,36 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+# Trace configs
+
+menu "Logging"
+
+config LOG_BACKEND_SOF_PROBE
+	bool "Logging backend with SOF probes"
+	depends on LOG
+	select LOG_OUTPUT
+	help
+		Enable backend for log output via SOF probe interface.
+		Probe interface allows to transmit logs and PCM data, muxed over
+		a shared DMA channel.
+		Logging is enabled by setting up a probe point with
+		probe purpose value of PROBE_PURPOSE_LOGGING.
+
+config LOG_BACKEND_SOF_PROBE_OUTPUT_DICTIONARY
+	bool "Dictionary"
+	select LOG_DICTIONARY_SUPPORT
+	help
+		Set output format of the SOF probe logging backend to
+		Zephyr log dictionary.
+		The resulting log file can be parsed with tools in
+		zephyr/scripts/logging/dictionary
+		A dictionary for the binary is created during build.
+
+config LOG_BACKEND_SOF_PROBE_OUTPUT
+	int "Set logging output format"
+	default 1 if LOG_MIPI_SYST_ENABLE
+	default 2 if LOG_BACKEND_SOF_PROBE_OUTPUT_DICTIONARY
+	default 0 # Text encoding is default
+        help
+                Set the logging format for SOF probe output.
+
+endmenu

src/logging/log_backend_probe.c

@@ -0,0 +1,111 @@
+// SPDX-License-Identifier: BSD-3-Clause
+//
+// Copyright(c) 2022 Intel Corporation. All rights reserved.
+
+#include <zephyr/logging/log_backend.h>
+#include <zephyr/logging/log_core.h>
+#include <zephyr/logging/log_output.h>
+#include <zephyr/logging/log_backend_std.h>
+#include <zephyr/zephyr.h>
+
+#include <sof/audio/buffer.h>
+#include <sof/ipc/topology.h>
+#include <sof/lib/memory.h>
+#include <sof/lib/notifier.h>
+#include <sof/probe/probe.h>
+
+/*
+ * A lock is needed as log_process() and log_panic() have no internal locks
+ * to prevent concurrency. Meaning if log_process is called after
+ * log_panic was called previously, log_process may happen from another
+ * CPU and calling context than the log processing thread running in
+ * the background. On an SMP system this is a race.
+ *
+ * This caused a race on the output trace such that the logging output
+ * was garbled and useless.
+ */
+static struct k_spinlock probe_lock;
+
+static uint32_t probe_log_format_current = CONFIG_LOG_BACKEND_SOF_PROBE_OUTPUT;
+
+#define LOG_BUF_SIZE 80
+static uint8_t log_buf[LOG_BUF_SIZE];
+
+static probe_logging_hook_t probe_hook;
+
+static int probe_char_out(uint8_t *data, size_t length, void *ctx)
+{
+	if (probe_hook)
+		probe_hook(data, length);
+
+	return length;
+}
+
+LOG_OUTPUT_DEFINE(log_output_adsp_probe, probe_char_out, log_buf, sizeof(log_buf));
+
+static uint32_t format_flags(void)
+{
+	uint32_t flags = LOG_OUTPUT_FLAG_LEVEL | LOG_OUTPUT_FLAG_TIMESTAMP;
+
+	if (IS_ENABLED(CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP))
+		flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
+
+	return flags;
+}
+
+static void probe_log_panic(struct log_backend const *const backend)
+{
+	k_spinlock_key_t key = k_spin_lock(&probe_lock);
+
+	log_backend_std_panic(&log_output_adsp_probe);
+
+	k_spin_unlock(&probe_lock, key);
+}
+
+static void probe_log_dropped(const struct log_backend *const backend,
+			      uint32_t cnt)
+{
+	log_output_dropped_process(&log_output_adsp_probe, cnt);
+}
+
+static void probe_log_process(const struct log_backend *const backend,
+			      union log_msg_generic *msg)
+{
+	log_format_func_t log_output_func = log_format_func_t_get(probe_log_format_current);
+
+	k_spinlock_key_t key = k_spin_lock(&probe_lock);
+
+	log_output_func(&log_output_adsp_probe, &msg->log, format_flags());
+
+	k_spin_unlock(&probe_lock, key);
+}
+
+static int probe_log_format_set(const struct log_backend *const backend, uint32_t log_type)
+{
+	probe_log_format_current = log_type;
+	return 0;
+}
+
+/**
+ * Lazily initialized, while the DMA may not be setup we continue
+ * to buffer log messages untilt he buffer is full.
+ */
+static void probe_log_init(const struct log_backend *const backend)
+{
+	ARG_UNUSED(backend);
+}
+
+const struct log_backend_api log_backend_adsp_probe_api = {
+	.process = probe_log_process,
+	.dropped = IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE) ? NULL : probe_log_dropped,
+	.panic = probe_log_panic,
+	.format_set = probe_log_format_set,
+	.init = probe_log_init,
+};
+
+LOG_BACKEND_DEFINE(log_backend_adsp_probe, log_backend_adsp_probe_api, true);
+
+void probe_logging_init(probe_logging_hook_t fn)
+{
+	probe_hook = fn;
+}