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]>

app/boards/intel_adsp_ace15_mtpm.conf

@@ -43,6 +43,7 @@ CONFIG_INTEL_ADSP_TIMER=y
 CONFIG_MM_DRV_INTEL_ADSP_TLB_REMAP_UNUSED_RAM=y
 CONFIG_AMS=y
 CONFIG_COUNTER=y
+CONFIG_TELEMETRY=y
 
 CONFIG_HEAP_MEM_POOL_SIZE=8192
 CONFIG_L3_HEAP=y

app/boards/intel_adsp_ace20_lnl.conf

@@ -37,6 +37,7 @@ CONFIG_INTEL_ADSP_TIMER=y
 CONFIG_MM_DRV_INTEL_ADSP_TLB_REMAP_UNUSED_RAM=y
 CONFIG_AMS=y
 CONFIG_COUNTER=y
+CONFIG_TELEMETRY=y
 
 CONFIG_HEAP_MEM_POOL_SIZE=8192
 CONFIG_L3_HEAP=y

src/audio/base_fw.c

@@ -20,6 +20,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>
@@ -577,6 +579,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(sof telemetry.c)

src/debug/telemetry/telemetry.c

@@ -0,0 +1,137 @@
+// SPDX-License-Identifier: BSD-3-Clause
+//
+// Copyright(c) 2023 Intel Corporation. All rights reserved.
+//
+// Author: Tobiasz Dryjanski <[email protected]>
+
+#include <errno.h>
+#include <limits.h>
+#include <stdbool.h>
+#include <stddef.h>
+#include <stdint.h>
+#include <adsp_debug_window.h>
+#include <mem_window.h>
+#include <zephyr/debug/sparse.h>
+#include <sof/debug/telemetry/telemetry.h>
+#include <sof/audio/module_adapter/module/generic.h>
+
+
+/* systic vars */
+int systick_counter;
+int prev_ccount;
+int perf_period_sum_;
+int perf_period_cnt_;
+struct perf_queue perf_queue = {0};
+
+static void perf_queue_append(struct perf_queue *q, size_t element)
+{
+	if (!q->full) {
+		q->elements[q->index] = element;
+		q->sum += element;
+		q->index++;
+		q->size++;
+		if (q->index >= AVG_PERF_MEAS_DEPTH) {
+			q->index = 0;
+			q->size = 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 >= AVG_PERF_MEAS_DEPTH)
+			q->index = 0;
+	}
+}
+
+static size_t perf_queue_avg(struct perf_queue *q)
+{
+	if (!q->size)
+		return 0;
+	return q->sum / q->size;
+}
+
+int telemetry_init(void)
+{
+	/* systick_init */
+	uint8_t slot_num = 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;
+
+	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_sys_tick_count = 0;
+		systick_info[i].max_sys_tick_count = 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 update_telemetry(uint32_t begin_ccount, uint32_t current_ccount)
+{
+	++systick_counter;
+	int prid = cpu_get_id();
+
+	struct telemetry_wnd_data *wnd_data =
+		(struct telemetry_wnd_data *)ADSP_DW->slots[DW_TELEMETRY_SLOT];
+	struct system_tick_info *systick_info =
+		(struct system_tick_info *)wnd_data->system_tick_info;
+
+	systick_info[prid].count = systick_counter;
+	systick_info[prid].last_sys_tick_count = current_ccount - begin_ccount;
+	systick_info[prid].max_sys_tick_count =
+			MAX(current_ccount - begin_ccount,
+			    systick_info[prid].max_sys_tick_count);
+	systick_info[prid].last_ccount = current_ccount;
+
+	#ifdef PERFORMANCE_MEASUREMENTS
+	const size_t measured_systick = begin_ccount - prev_ccount;
+
+	prev_ccount = begin_ccount;
+	if (systick_counter > 2) {
+		perf_period_sum_ += measured_systick;
+		perf_period_cnt_ = (perf_period_cnt_ + 1) % AVG_PERF_MEAS_PERIOD;
+		if (perf_period_cnt_ == 0) {
+			/* Append average of last AVG_PERF_MEAS_PERIOD runs */
+			perf_queue_append(&perf_queue, perf_period_sum_ / AVG_PERF_MEAS_PERIOD);
+			perf_period_sum_ = 0;
+			/* Calculate average from all buckets */
+			systick_info[prid].avg_utilization = perf_queue_avg(&perf_queue);
+		}
+		if (systick_counter > 1) {
+			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);
+		}
+		if ((systick_counter % 0x1000) == 0)
+			systick_info[prid].peak_utilization_4k = 0;
+		if ((systick_counter % 0x2000) == 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,86 @@
+/* SPDX-License-Identifier: BSD-3-Clause
+ *
+ * Copyright(c) 2023 Intel Corporation. All rights reserved.
+ */
+
+#ifndef __SOF_TELEMETRY_H__
+#define __SOF_TELEMETRY_H__
+
+/* Slot in memory window 2 to be used as telemetry slot */
+#define DW_TELEMETRY_SLOT 1
+/* Memory of average algorithm of performance queue */
+#define AVG_PERF_MEAS_DEPTH 64
+/* Number of runs taken to calculate average (algorithm resolution) */
+#define AVG_PERF_MEAS_PERIOD 16
+/* disables calculating systick_averages */
+#define PERFORMANCE_MEASUREMENTS
+
+struct system_tick_info {
+	uint32_t count;
+	uint32_t last_sys_tick_count;
+	uint32_t max_sys_tick_count;
+	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];
+};
+
+/*
+ * 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];
+	 */
+};
+
+/* Reference FW used a normal Queue here.
+ * Implementing simplified queue just for avg calculation.
+ * Queue is circular, oldest element replaced by latest
+ */
+struct perf_queue {
+	size_t elements[AVG_PERF_MEAS_DEPTH];
+	/* number of items AND index of next empty box */
+	size_t count;
+	/* head if queue is full, else tail */
+	size_t index; //next empty
+	uint8_t full;
+	size_t size;
+	size_t sum;
+};
+
+void update_telemetry(uint32_t begin_ccount, uint32_t current_ccount);
+
+#endif /*__SOF_TELEMETRY_H__ */

src/schedule/zephyr_ll.c

@@ -15,6 +15,9 @@
 #include <sof/lib/perf_cnt.h>
 #include <zephyr/kernel.h>
 #include <ipc4/base_fw.h>
+#ifdef CONFIG_TELEMETRY
+#include <sof/debug/telemetry/telemetry.h>
+#endif
 
 LOG_MODULE_REGISTER(ll_schedule, CONFIG_SOF_LOG_LEVEL);
 
@@ -252,6 +255,18 @@ static void zephyr_ll_run(void *data)
 		       NOTIFIER_TARGET_CORE_LOCAL, NULL, 0);
 }
 
+static void schedule_ll_callback(void *data)
+{
+#ifdef CONFIG_TELEMETRY
+	const uint32_t begin_count = xthal_get_ccount();
+#endif
+	zephyr_ll_run(data);
+#ifdef CONFIG_TELEMETRY
+	const uint32_t current_count = xthal_get_ccount();
+	update_telemetry(begin_count, current_count);
+#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 +342,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

@@ -900,6 +900,10 @@ zephyr_library_sources_ifdef(CONFIG_SOF_BOOT_TEST
        boot_test.c
 )
 
+zephyr_library_sources_ifdef( CONFIG_TELEMETRY
+       ${SOF_SRC_PATH}/debug/telemetry/telemetry.c
+)
+
 zephyr_library_link_libraries(SOF)
 target_link_libraries(SOF INTERFACE zephyr_interface)
 

zephyr/Kconfig

@@ -77,4 +77,10 @@ config SOF_BOOT_TEST
 	  initialized. After that SOF will continue running and be usable as
 	  usual.
 
+config TELEMETRY
+	bool "enable telemetry"
+	default n
+	help
+	  Enable Telemetry
+
 endif