Tools: Testbench: Track and print heap usage for modules

This patch adds to end to sof-testbench4 run print of peak
heap consumption for each module. The information is retrieved
from heap_high_water_mark data that is tracked by module adapter
for each module.

Signed-off-by: Seppo Ingalsuo <seppo.ingalsuo@linux.intel.com>

Author: singalsu

tools/testbench/include/testbench/utils.h

@@ -148,6 +148,11 @@ struct testbench_prm {
 #endif
 };
 
+struct tb_heap_usage_record {
+	char *module_name;
+	size_t heap_max;
+};
+
 extern int debug;
 
 int tb_decode_enum(struct snd_soc_tplg_enum_control *enum_ctl, char *token);
@@ -169,6 +174,7 @@ int tb_set_up_all_pipelines(struct testbench_prm *tp);
 int tb_setup(struct sof *sof, struct testbench_prm *tp);
 bool tb_is_pipeline_enabled(struct testbench_prm *tp, int pipeline_id);
 bool tb_schedule_pipeline_check_state(struct testbench_prm *tp);
+void tb_collect_heap_usage(struct testbench_prm *tp, struct tb_heap_usage_record *rec, int *count);
 void tb_debug_print(char *message);
 void tb_free(struct sof *sof);
 void tb_free_topology(struct testbench_prm *tp);

tools/testbench/testbench.c

@@ -240,7 +240,9 @@ static int parse_input_args(int argc, char **argv, struct testbench_prm *tp)
 	return ret;
 }
 
-static void test_pipeline_stats(struct testbench_prm *tp, long long delta_t)
+static void test_pipeline_stats(struct testbench_prm *tp, long long delta_t,
+				struct tb_heap_usage_record *heap_records,
+				int heap_records_count)
 {
 	long long file_cycles, pipeline_cycles;
 	float pipeline_mcps;
@@ -284,22 +286,28 @@ static void test_pipeline_stats(struct testbench_prm *tp, long long delta_t)
 	frames_out = n_out / tp->channels_out;
 	printf("Input sample (frame) count: %d (%d)\n", n_in, n_in / tp->channels_in);
 	printf("Output sample (frame) count: %d (%d)\n", n_out, frames_out);
+	if (heap_records_count > 0) {
+		for (i = 0; i < heap_records_count; i++)
+			printf("Heap usage for module %s: %u bytes\n",
+			       heap_records[i].module_name, (uint32_t)heap_records[i].heap_max);
+	}
+
+	printf("\n");
 	if (tp->total_cycles) {
 		pipeline_cycles = tp->total_cycles - file_cycles;
 		pipeline_mcps = (float)pipeline_cycles * tp->fs_out / frames_out / 1e6;
+		if (tb_check_trace(LOG_LEVEL_DEBUG))
+			printf("Warning: Use -d 3 or smaller value to avoid traces to increase MCPS.\n");
+
 		printf("Total execution cycles: %lld\n", tp->total_cycles);
 		printf("File component cycles: %lld\n", file_cycles);
 		printf("Pipeline cycles: %lld\n", pipeline_cycles);
-		printf("Pipeline MCPS: %6.2f\n", pipeline_mcps);
-		if (tb_check_trace(LOG_LEVEL_DEBUG))
-			printf("Warning: Use -d 3 or smaller value to avoid traces to increase MCPS.\n");
+		printf("Pipeline MCPS: %6.2f\n\n", pipeline_mcps);
 	}
 
 	if (delta_t)
-		printf("Total execution time: %lld us, %.2f x realtime\n",
-		       delta_t, (float)frames_out / tp->fs_out * 1000000 / delta_t);
-
-	printf("\n");
+		printf("Total execution time: %lld us, %.2f x realtime\n\n", delta_t,
+		       (float)frames_out / tp->fs_out * 1000000 / delta_t);
 }
 
 /*
@@ -308,14 +316,16 @@ static void test_pipeline_stats(struct testbench_prm *tp, long long delta_t)
  */
 static int pipline_test(struct testbench_prm *tp)
 {
-	float samples_to_ns;
-	int dp_count = 0;
-	struct timespec td0, td1;
+	struct tb_heap_usage_record heap_usage_records[TB_NUM_WIDGETS_SUPPORTED];
 	struct file_state *out_stat;
-	long long delta_t;
+	struct timespec td0 = {0}, td1 = {0};
+	long long delta_t = 0;
 	int64_t next_control_ns;
 	int64_t time_ns;
+	float samples_to_ns;
 	int err;
+	int heap_usage_records_count = 0;
+	int dp_count = 0;
 
 	/* build, run and teardown pipelines */
 	while (dp_count < tp->dynamic_pipeline_iterations) {
@@ -392,8 +402,10 @@ static int pipline_test(struct testbench_prm *tp)
 		}
 
 		tb_schedule_pipeline_check_state(tp); /* Once more to flush out remaining data */
-
 		tb_gettime(&td1);
+		delta_t = (td1.tv_sec - td0.tv_sec) * 1000000;
+		delta_t += (td1.tv_nsec - td0.tv_nsec) / 1000;
+		tb_collect_heap_usage(tp, heap_usage_records, &heap_usage_records_count);
 
 out:
 		err = tb_set_reset_state(tp);
@@ -403,12 +415,7 @@ static int pipline_test(struct testbench_prm *tp)
 			break;
 		}
 
-		/* TODO: This should be printed after reset and free to get cleaner output
-		 * but the file internal status would be lost there.
-		 */
-		delta_t = (td1.tv_sec - td0.tv_sec) * 1000000;
-		delta_t += (td1.tv_nsec - td0.tv_nsec) / 1000;
-		test_pipeline_stats(tp, delta_t);
+		test_pipeline_stats(tp, delta_t, heap_usage_records, heap_usage_records_count);
 
 		err = tb_free_all_pipelines(tp);
 		if (err < 0) {

tools/testbench/utils_ipc3.c

@@ -441,4 +441,8 @@ int tb_set_bytes_control(struct testbench_prm *tp, struct tb_ctl *ctl, uint32_t
 	return 0;
 }
 
+void tb_collect_heap_usage(struct testbench_prm *tp, struct tb_heap_usage_record *rec, int *count)
+{
+}
+
 #endif /* CONFIG_IPC_MAJOR_3 */

tools/testbench/utils_ipc4.c

@@ -4,6 +4,7 @@
 
 #if CONFIG_IPC_MAJOR_4
 
+#include <sof/audio/module_adapter/module/generic.h>
 #include <sof/audio/component_ext.h>
 #include <sof/lib/notifier.h>
 #include <sof/audio/component_ext.h>
@@ -702,4 +703,41 @@ int tb_set_bytes_control(struct testbench_prm *tp, struct tb_ctl *ctl, uint32_t
 				  (struct sof_abi_hdr *)data);
 }
 
+void tb_collect_heap_usage(struct testbench_prm *tp, struct tb_heap_usage_record *records,
+			   int *count_out)
+{
+	struct list_item *item;
+	size_t hwm;
+	int count = 0;
+
+	list_for_item(item, &tp->widget_list) {
+		struct tplg_comp_info *info = container_of(item, struct tplg_comp_info, item);
+		uint32_t comp_id = IPC4_COMP_ID(info->module_id, info->instance_id);
+		struct comp_dev *dev = ipc4_get_comp_dev(comp_id);
+
+		if (!dev || !dev->mod)
+			continue;
+
+		/* In testbench environment, skip AIF/DAI because they are not real components. */
+		if (info->type == SND_SOC_TPLG_DAPM_AIF_IN ||
+		    info->type == SND_SOC_TPLG_DAPM_AIF_OUT ||
+		    info->type == SND_SOC_TPLG_DAPM_DAI_IN ||
+		    info->type == SND_SOC_TPLG_DAPM_DAI_OUT)
+			continue;
+
+		if (count >= TB_NUM_WIDGETS_SUPPORTED) {
+			fprintf(stderr, "Error: Too many components for heap records, max %d.\n",
+				TB_NUM_WIDGETS_SUPPORTED);
+			break;
+		}
+
+		module_adapter_heap_usage(dev->mod, &hwm);
+		records[count].module_name = info->name;
+		records[count].heap_max = hwm;
+		count++;
+	}
+
+	*count_out = count;
+}
+
 #endif /* CONFIG_IPC_MAJOR_4 */