From b8e102ecb79b3a12c602d33f0cf5a41429533691 Mon Sep 17 00:00:00 2001 From: Aaron Odell Date: Tue, 4 Apr 2023 22:14:32 -0700 Subject: [PATCH] [kernel][thread] Track per-thread scheduling statistics Track per-thread runtime, last scheduled time, and count of times scheduled. Query via existing threadstats CLI. --- kernel/debug.c | 1 + kernel/include/kernel/thread.h | 13 +++++++++++++ kernel/thread.c | 35 ++++++++++++++++++++++++++++++++-- 3 files changed, 47 insertions(+), 2 deletions(-) diff --git a/kernel/debug.c b/kernel/debug.c index ba5bb58f..2a6a34bd 100644 --- a/kernel/debug.c +++ b/kernel/debug.c @@ -87,6 +87,7 @@ static int cmd_threadstats(int argc, const console_cmd_args *argv) { printf("\ttimers: %lu\n", thread_stats[i].timers); } + dump_threads_stats(); return 0; } diff --git a/kernel/include/kernel/thread.h b/kernel/include/kernel/thread.h index ddfe983f..a3ffde4e 100644 --- a/kernel/include/kernel/thread.h +++ b/kernel/include/kernel/thread.h @@ -69,6 +69,14 @@ enum thread_tls_list { #define THREAD_MAGIC (0x74687264) // 'thrd' +#if THREAD_STATS +struct thread_specific_stats { + lk_bigtime_t total_run_time; + lk_bigtime_t last_run_timestamp; + ulong schedules; // times this thread is scheduled to run. +}; +#endif + typedef struct thread { int magic; struct list_node thread_list_node; @@ -110,6 +118,10 @@ typedef struct thread { uintptr_t tls[MAX_TLS_ENTRY]; char name[32]; + +#if THREAD_STATS + struct thread_specific_stats stats; +#endif } thread_t; #if WITH_SMP @@ -163,6 +175,7 @@ void dump_thread(thread_t *t); void arch_dump_thread(thread_t *t); void dump_all_threads(void); void dump_all_threads_unlocked(void); +void dump_threads_stats(void); /* scheduler routines */ void thread_yield(void); /* give up the cpu voluntarily */ diff --git a/kernel/thread.c b/kernel/thread.c index cfb713af..a77464f7 100644 --- a/kernel/thread.c +++ b/kernel/thread.c @@ -516,12 +516,17 @@ void thread_resched(void) { #if THREAD_STATS THREAD_STATS_INC(context_switches); + lk_bigtime_t now = current_time_hires(); if (thread_is_idle(oldthread)) { - lk_bigtime_t now = current_time_hires(); thread_stats[cpu].idle_time += now - thread_stats[cpu].last_idle_timestamp; + } else { + oldthread->stats.total_run_time += now - oldthread->stats.last_run_timestamp; } if (thread_is_idle(newthread)) { - thread_stats[cpu].last_idle_timestamp = current_time_hires(); + thread_stats[cpu].last_idle_timestamp = now; + } else { + newthread->stats.last_run_timestamp = now; + newthread->stats.schedules++; } #endif @@ -1010,6 +1015,32 @@ void dump_all_threads(void) { THREAD_UNLOCK(state); } +#if THREAD_STATS +void dump_threads_stats(void) { + thread_t *t; + + THREAD_LOCK(state); + list_for_every_entry (&thread_list, t, thread_t, thread_list_node) { + if (t->magic != THREAD_MAGIC) { + dprintf(INFO, "bad magic on thread struct %p, aborting.\n", t); + hexdump(t, sizeof(thread_t)); + break; + } + if (thread_is_idle(t)) { + continue; + } + // thread specific stats + dprintf(INFO, "\t(%s):\n", t->name); + dprintf(INFO, "\t\tScheduled: %ld\n", t->stats.schedules); + uint percent = (t->stats.total_run_time * 10000) / current_time_hires(); + dprintf(INFO, "\t\tTotal run time: %lld, %u.%02u%%\n", t->stats.total_run_time, + percent / 100, percent % 100); + dprintf(INFO, "\t\tLast time run: %lld\n", t->stats.last_run_timestamp); + } + THREAD_UNLOCK(state); +} +#endif + /** @} */