telemetry: Add systick_info part of telemetry

Introduces telemetry structure into debug memory window. Adds
systick_info which counts execution time of LL tasks. DP tasks are not
supported yet.

Signed-off-by: Tobiasz Dryjanski <[email protected]>

src/audio/base_fw.c

@@ -19,6 +19,8 @@
 #include <sof/audio/module_adapter/module/generic.h>
 #include <sof/schedule/dp_schedule.h>
 #include <sof/schedule/ll_schedule.h>
+#include "adsp_debug_window.h"
+#include "mem_window.h"
 
 #if CONFIG_ACE_V1X_ART_COUNTER || CONFIG_ACE_V1X_RTC_COUNTER
 #include <zephyr/device.h>
@@ -569,6 +571,8 @@ static int basefw_set_large_config(struct comp_dev *dev,
 	switch (param_id) {
 	case IPC4_FW_CONFIG:
 		return basefw_set_fw_config(first_block, last_block, data_offset, data);
+	case IPC4_PERF_MEASUREMENTS_STATE:
+		return 0;
 	case IPC4_SYSTEM_TIME:
 		return basefw_set_system_time(param_id, first_block,
 						last_block, data_offset, data);

src/debug/telemetry/CMakeLists.txt

@@ -0,0 +1,3 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+add_local_sources_ifdef(CONFIG_SOF_TELEMETRY sof telemetry.c)

src/debug/telemetry/Kconfig

@@ -0,0 +1,11 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+config SOF_TELEMETRY
+	bool "enable telemetry"
+	default n
+	help
+	  Enables telemetry. Enables performance measurements and debug utilities
+	  that use memory window 2 (debug window) as interface. Measurements include
+	  systick_info measurement which measures scheduler task performance and may
+	  slightly affect overall performance.
+

src/debug/telemetry/telemetry.c

@@ -0,0 +1,151 @@
+// SPDX-License-Identifier: BSD-3-Clause
+//
+// Copyright(c) 2024 Intel Corporation. All rights reserved.
+//
+// Author: Tobiasz Dryjanski <[email protected]>
+
+#include <zephyr/debug/sparse.h>
+
+#include <sof/audio/module_adapter/module/generic.h>
+#include <sof/debug/telemetry/telemetry.h>
+
+#include <ipc/trace.h>
+
+#include <adsp_debug_window.h>
+#include <errno.h>
+#include <limits.h>
+#include <mem_window.h>
+#include <stdbool.h>
+#include <stddef.h>
+#include <stdint.h>
+
+LOG_MODULE_DECLARE(ipc, CONFIG_SOF_LOG_LEVEL);
+
+/* Systic variables, one set per core */
+static int telemetry_systick_counter[CONFIG_MAX_CORE_COUNT];
+static int telemetry_prev_ccount[CONFIG_MAX_CORE_COUNT];
+static int telemetry_perf_period_sum[CONFIG_MAX_CORE_COUNT];
+static int telemetry_perf_period_cnt[CONFIG_MAX_CORE_COUNT];
+static struct telemetry_perf_queue telemetry_perf_queue[CONFIG_MAX_CORE_COUNT];
+
+static void telemetry_perf_queue_append(struct telemetry_perf_queue *q, size_t element)
+{
+	if (!q->full) {
+		q->elements[q->index] = element;
+		q->sum += element;
+		q->index++;
+		q->size++;
+		if (q->index >= SOF_AVG_PERF_MEAS_DEPTH) {
+			q->index = 0;
+			q->size = SOF_AVG_PERF_MEAS_DEPTH;
+			q->full = true;
+		}
+	} else {
+		/* no space, pop tail */
+		q->sum -= q->elements[q->index];
+		/* replace tail */
+		q->elements[q->index] = element;
+		q->sum += element;
+		/* move tail */
+		q->index++;
+		if (q->index >= SOF_AVG_PERF_MEAS_DEPTH)
+			q->index = 0;
+	}
+}
+
+static size_t telemetry_perf_queue_avg(struct telemetry_perf_queue *q)
+{
+	if (!q->size)
+		return 0;
+	return q->sum / q->size;
+}
+
+int telemetry_init(void)
+{
+	/* systick_init */
+	uint8_t slot_num = SOF_DW_TELEMETRY_SLOT;
+	volatile struct adsp_debug_window *window = ADSP_DW;
+	struct telemetry_wnd_data *wnd_data = (struct telemetry_wnd_data *)ADSP_DW->slots[slot_num];
+	struct system_tick_info *systick_info =
+			(struct system_tick_info *)wnd_data->system_tick_info;
+
+	tr_info(&ipc_tr, "Telemetry enabled. May affect performance");
+
+	window->descs[slot_num].type = ADSP_DW_SLOT_TELEMETRY;
+	window->descs[slot_num].resource_id = 0;
+	wnd_data->separator_1 = 0x0000C0DE;
+
+	/* Zero values per core */
+	for (int i = 0; i < CONFIG_MAX_CORE_COUNT; i++) {
+		systick_info[i].count = 0;
+		systick_info[i].last_time_elapsed = 0;
+		systick_info[i].max_time_elapsed = 0;
+		systick_info[i].last_ccount = 0;
+		systick_info[i].avg_utilization = 0;
+		systick_info[i].peak_utilization = 0;
+		systick_info[i].peak_utilization_4k = 0;
+		systick_info[i].peak_utilization_8k = 0;
+	}
+	return 0;
+}
+
+void telemetry_update(uint32_t begin_stamp, uint32_t current_stamp)
+{
+	int prid = cpu_get_id();
+
+	++telemetry_systick_counter[prid];
+
+	struct telemetry_wnd_data *wnd_data =
+		(struct telemetry_wnd_data *)ADSP_DW->slots[SOF_DW_TELEMETRY_SLOT];
+	struct system_tick_info *systick_info =
+		(struct system_tick_info *)wnd_data->system_tick_info;
+
+	systick_info[prid].count = telemetry_systick_counter[prid];
+	systick_info[prid].last_time_elapsed = current_stamp - begin_stamp;
+	systick_info[prid].max_time_elapsed =
+			MAX(current_stamp - begin_stamp,
+			    systick_info[prid].max_time_elapsed);
+	systick_info[prid].last_ccount = current_stamp;
+
+#ifdef SOF_PERFORMANCE_MEASUREMENTS
+	const size_t measured_systick = begin_stamp - telemetry_prev_ccount[prid];
+
+	telemetry_prev_ccount[prid] = begin_stamp;
+	if (telemetry_systick_counter[prid] > 2) {
+		telemetry_perf_period_sum[prid] += measured_systick;
+		telemetry_perf_period_cnt[prid] =
+			(telemetry_perf_period_cnt[prid] + 1) % SOF_AVG_PERF_MEAS_PERIOD;
+		if (telemetry_perf_period_cnt[prid] == 0) {
+			/* Append average of last SOF_AVG_PERF_MEAS_PERIOD runs */
+			telemetry_perf_queue_append(&telemetry_perf_queue[prid],
+						    telemetry_perf_period_sum[prid]
+						    / SOF_AVG_PERF_MEAS_PERIOD);
+			telemetry_perf_period_sum[prid] = 0;
+			/* Calculate average from all buckets */
+			systick_info[prid].avg_utilization =
+				telemetry_perf_queue_avg(&telemetry_perf_queue[prid]);
+		}
+
+		systick_info[prid].peak_utilization =
+			MAX(systick_info[prid].peak_utilization,
+			    measured_systick);
+		systick_info[prid].peak_utilization_4k =
+			MAX(systick_info[prid].peak_utilization_4k,
+			    measured_systick);
+		systick_info[prid].peak_utilization_8k =
+			MAX(systick_info[prid].peak_utilization_8k,
+			    measured_systick);
+
+		/* optimized: counter % 0x1000 */
+		if ((telemetry_systick_counter[prid] & 0xfff) == 0)
+			systick_info[prid].peak_utilization_4k = 0;
+		/* optimized: counter % 0x2000 */
+		if ((telemetry_systick_counter[prid] & 0x1fff) == 0)
+			systick_info[prid].peak_utilization_8k = 0;
+	}
+#endif
+}
+
+/* init telemetry using Zephyr*/
+SYS_INIT(telemetry_init, APPLICATION, CONFIG_APPLICATION_INIT_PRIORITY);
+

src/include/sof/debug/telemetry/telemetry.h

@@ -0,0 +1,88 @@
+/* SPDX-License-Identifier: BSD-3-Clause
+ *
+ * Copyright(c) 2024 Intel Corporation. All rights reserved.
+ */
+
+#ifndef __SOF_TELEMETRY_H__
+#define __SOF_TELEMETRY_H__
+
+/* Slot in memory window 2 (Debug Window) to be used as telemetry slot */
+#define SOF_DW_TELEMETRY_SLOT 1
+/* Memory of average algorithm of performance queue */
+#define SOF_AVG_PERF_MEAS_DEPTH 64
+/* Number of runs taken to calculate average (algorithm resolution) */
+#define SOF_AVG_PERF_MEAS_PERIOD 16
+/* disables calculating systick_averages */
+#define SOF_PERFORMANCE_MEASUREMENTS
+
+/* Systick here is not to be confused with neither Zephyr tick nor SOF scheduler tick,
+ * it's a legacy name for counting execution time
+ */
+struct system_tick_info {
+	uint32_t count;
+	uint32_t last_time_elapsed;
+	uint32_t max_time_elapsed;
+	uint32_t last_ccount;
+	uint32_t avg_utilization;
+	uint32_t peak_utilization;
+	uint32_t peak_utilization_4k;
+	uint32_t peak_utilization_8k;
+	uint32_t rsvd[2];
+} __packed;
+
+/*
+ * This is the structure of telemetry data in memory window.
+ * If you need to define a field, you should also define the fields before it to
+ * keep the internal structures aligned with each other.
+ */
+struct telemetry_wnd_data {
+	uint32_t separator_1;
+	struct system_tick_info system_tick_info[CONFIG_MAX_CORE_COUNT];
+	/*
+	 * uint32_t separator_2;
+	 * deadlock_info_s deadlock_info[FW_REPORTED_MAX_CORES_COUNT];
+	 * uint32_t separator_3;
+	 * assert_info_s assert_info;
+	 * uint32_t separator_4;
+	 * xxxruns_info_s xxxruns_info;
+	 * uint32_t separator_5;
+	 * performance_info_s performance_info;
+	 * uint32_t separator_6;
+	 * mem_pools_info_s mem_pools_info;
+	 * uint32_t separator_7;
+	 * timeout_info_s timeout_info;
+	 * uint32_t separator_8;
+	 * ulp_telemetry_s ulp_telemetry;
+	 * uint32_t separator_9;
+	 * transition_info_s   evad_transition_info;
+	 * uint32_t separator_10;
+	 * task_info_s task_info[FW_MAX_REPORTED_TASKS];
+	 * uint32_t separator_11;
+	 * transition_info_s d0i3_info[FW_REPORTED_MAX_CORES_COUNT];
+	 * uint32_t separator_12;
+	 * interrupt_stats_info_s interrupt_stats;
+	 * uint32_t separator_13;
+	 * loaded_libraries_s loaded_libraries;
+	 * //uint32_t __pad_for_exception_record;
+	 * uint32_t separator_exception;
+	 * CoreExceptionRecord core_exception_record[FW_REPORTED_MAX_CORES_COUNT];
+	 */
+} __packed;
+
+/* Reference FW used a normal Queue here.
+ * Implementing simplified queue just for avg calculation.
+ * Queue is circular, oldest element replaced by latest
+ */
+struct telemetry_perf_queue {
+	size_t elements[SOF_AVG_PERF_MEAS_DEPTH];
+	/* next empty element, head if queue is full, else tail */
+	size_t index;
+	uint8_t full;
+	/* number of items AND index of next empty box */
+	size_t size;
+	size_t sum;
+};
+
+void telemetry_update(uint32_t begin_ccount, uint32_t current_ccount);
+
+#endif /*__SOF_TELEMETRY_H__ */

src/schedule/zephyr_ll.c

@@ -15,6 +15,7 @@
 #include <sof/lib/perf_cnt.h>
 #include <zephyr/kernel.h>
 #include <ipc4/base_fw.h>
+#include <sof/debug/telemetry/telemetry.h>
 
 LOG_MODULE_REGISTER(ll_schedule, CONFIG_SOF_LOG_LEVEL);
 
@@ -252,6 +253,19 @@ static void zephyr_ll_run(void *data)
 		       NOTIFIER_TARGET_CORE_LOCAL, NULL, 0);
 }
 
+static void schedule_ll_callback(void *data)
+{
+#ifdef CONFIG_SOF_TELEMETRY
+	const uint32_t begin_stamp = (uint32_t)sof_cycle_get_64();
+#endif
+	zephyr_ll_run(data);
+#ifdef CONFIG_SOF_TELEMETRY
+	const uint32_t current_stamp = (uint32_t)sof_cycle_get_64();
+
+	telemetry_update(begin_stamp, current_stamp);
+#endif
+}
+
 /*
  * Called once for periodic tasks or multiple times for one-shot tasks
  * TODO: start should be ignored in Zephyr LL scheduler implementation. Tasks
@@ -327,7 +341,7 @@ static int zephyr_ll_task_schedule_common(struct zephyr_ll *sch, struct task *ta
 
 	zephyr_ll_unlock(sch, &flags);
 
-	ret = domain_register(sch->ll_domain, task, &zephyr_ll_run, sch);
+	ret = domain_register(sch->ll_domain, task, &schedule_ll_callback, sch);
 	if (ret < 0)
 		tr_err(&ll_tr, "zephyr_ll_task_schedule: cannot register domain %d",
 		       ret);

zephyr/CMakeLists.txt

@@ -146,6 +146,7 @@ endmacro()
 
 add_subdirectory(../src/init/ init_unused_install/)
 add_subdirectory(../src/ipc/  ipc_unused_install/)
+add_subdirectory(../src/debug/telemetry/  telemetry_unused_install/)
 add_subdirectory(test/)