kernel: extend thread runtime stats

When the new Kconfig option CONFIG_SCHED_THREAD_USAGE_ANALYSIS
is enabled, additional timing stats are collected during context
switches. This extra information allows a developer to obtain the
the current, longest, average and total lengths of the time that
a thread has been scheduled to execute.

A developer can in turn use this information to tune their app and/or
alter their scheduling policies.

Signed-off-by: Peter Mitsis <peter.mitsis@intel.com>

include/kernel/stats.h

@@ -0,0 +1,26 @@
+/*
+ * Copyright (c) 2021, Intel Corporation
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+#ifndef ZEPHYR_INCLUDE_KERNEL_STATS_H_
+#define ZEPHYR_INCLUDE_KERNEL_STATS_H_
+
+#include <stdint.h>
+
+/*
+ * [k_cycle_stats] is used to track internal statistics about both thread
+ * and CPU usage.
+ */
+
+struct k_cycle_stats {
+	uint64_t  total;        /* total usage in cycles */
+#ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
+	uint64_t  current;      /* # of cycles in current usage window */
+	uint64_t  longest;      /* # of cycles in longest usage window */
+	uint32_t  num_windows;  /* # of usage windows */
+#endif
+};
+
+#endif

include/kernel/thread.h

@@ -11,6 +11,8 @@
 #include <sys/mem_manage.h>
 #endif
 
+#include <kernel/stats.h>
+
 /**
  * @typedef k_thread_entry_t
  * @brief Thread entry point function type.
@@ -118,7 +120,7 @@ struct _thread_base {
 #endif
 
 #ifdef CONFIG_SCHED_THREAD_USAGE
-	uint64_t usage;
+	struct k_cycle_stats  usage;   /* Track thread usage statistics */
 #endif
 };
 
@@ -172,6 +174,26 @@ struct _thread_userspace_local_data {
 typedef struct k_thread_runtime_stats {
 #ifdef CONFIG_SCHED_THREAD_USAGE
 	uint64_t execution_cycles;
+	/*
+	 * In the context of thread statistics, [execution_cycles] is the same
+	 * as the total # of non-idle cycles. In the context of CPU statistics,
+	 * it refers to the sum of non-idle + idle cycles.
+	 */
+#endif
+
+#ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
+	uint64_t current_cycles;      /* current # of non-idle cycles */
+	uint64_t peak_cycles;         /* peak # of non-idle cycles */
+	uint64_t total_cycles;        /* total # of non-idle cycles */
+	uint64_t average_cycles;      /* average # of non-idle cycles */
+
+	/*
+	 * This field is always zero for individual threads. It only comes
+	 * into play when gathering statistics for the CPU. In that case it
+	 * represents the total number of cycles spent idling.
+	 */
+
+	uint64_t idle_cycles;
 #endif
 }  k_thread_runtime_stats_t;
 

kernel/Kconfig

@@ -388,6 +388,17 @@ config SCHED_THREAD_USAGE
 	help
 	  Collect thread runtime info at context switch time
 
+config SCHED_THREAD_USAGE_ANALYSIS
+	bool "Analyze the collected thread runtime usage statistics"
+	default n
+	depends on SCHED_THREAD_USAGE
+	select INSTRUMENT_THREAD_SWITCHING if !USE_SWITCH
+	help
+	  Collect additional timing information related to thread scheduling
+	  for analysis purposes. This includes the total time that a thread
+	  has been scheduled, the longest time for which it was scheduled and
+	  others.
+
 config SCHED_THREAD_USAGE_ALL
 	bool "Collect total system runtime usage"
 	default y if SCHED_THREAD_USAGE

kernel/usage.c

@@ -31,35 +31,66 @@ static uint32_t usage_now(void)
 	return (now == 0) ? 1 : now;
 }
 
+/**
+ * Update the usage statistics for the specified CPU and thread
+ */
+static void sched_update_usage(struct k_thread *thread, uint32_t cycles)
+{
+#ifdef CONFIG_SCHED_THREAD_USAGE_ALL
+	if (z_is_idle_thread_object(thread)) {
+		_kernel.idle_thread_usage += cycles;
+	} else {
+		_kernel.all_thread_usage += cycles;
+	}
+#endif
+
+	thread->base.usage.total += cycles;
+
+#ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
+	thread->base.usage.current += cycles;
+
+	if (thread->base.usage.longest < thread->base.usage.current) {
+		thread->base.usage.longest = thread->base.usage.current;
+	}
+#endif
+}
+
 void z_sched_usage_start(struct k_thread *thread)
 {
+#ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
+	k_spinlock_key_t  key;
+
+	key = k_spin_lock(&usage_lock);
+
+	_current_cpu->usage0 = usage_now();
+
+	thread->base.usage.num_windows++;
+	thread->base.usage.current = 0;
+
+	k_spin_unlock(&usage_lock, key);
+#else
 	/* One write through a volatile pointer doesn't require
 	 * synchronization as long as _usage() treats it as volatile
 	 * (we can't race with _stop() by design).
 	 */
 
 	_current_cpu->usage0 = usage_now();
+#endif
 }
 
 void z_sched_usage_stop(void)
 {
-	k_spinlock_key_t k = k_spin_lock(&usage_lock);
+	struct _cpu     *cpu = _current_cpu;
-	uint32_t u0 = _current_cpu->usage0;
+	k_spinlock_key_t k   = k_spin_lock(&usage_lock);
+	uint32_t u0 = cpu->usage0;
 
 	if (u0 != 0) {
 		uint32_t dt = usage_now() - u0;
 
-#ifdef CONFIG_SCHED_THREAD_USAGE_ALL
+		sched_update_usage(cpu->current, dt);
-		if (z_is_idle_thread_object(_current)) {
-			_kernel.idle_thread_usage += dt;
-		} else {
-			_kernel.all_thread_usage += dt;
-		}
-#endif
-		_current->base.usage += dt;
 	}
 
-	_current_cpu->usage0 = 0;
+	cpu->usage0 = 0;
 	k_spin_unlock(&usage_lock, k);
 }
 
@@ -85,19 +116,30 @@ void z_sched_thread_usage(struct k_thread *thread,
 		 * running on the current core.
 		 */
 
-#ifdef CONFIG_SCHED_THREAD_USAGE_ALL
+		sched_update_usage(thread, dt);
-		if (z_is_idle_thread_object(thread)) {
-			_kernel.idle_thread_usage += dt;
-		} else {
-			_kernel.all_thread_usage += dt;
-		}
-#endif
 
-		thread->base.usage += dt;
 		cpu->usage0 = now;
 	}
 
-	stats->execution_cycles = thread->base.usage;
+	stats->execution_cycles = thread->base.usage.total;
+
+	/* Copy-out the thread's usage stats */
+
+#ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
+	stats->current_cycles = thread->base.usage.current;
+	stats->peak_cycles    = thread->base.usage.longest;
+	stats->total_cycles   = thread->base.usage.total;
+
+	if (thread->base.usage.num_windows == 0) {
+		stats->average_cycles = 0;
+	} else {
+		stats->average_cycles = stats->total_cycles /
+					thread->base.usage.num_windows;
+	}
+
+	stats->idle_cycles = 0;
+#endif
+	stats->execution_cycles = thread->base.usage.total;
 
 	k_spin_unlock(&usage_lock, key);
 }