Skip to content

Commit 151e137

Browse files
committed
schedule: zephyr_domain: make LL reporting build-time configurable
Add Kconfig options to enable and disable the low-latency scheduler statistics reporting, and to set the window size. Also add an option to set reporting to be done only for every other statistics window. This can be useful to exclude impact of the logging itself. With most current configurations and logging backends, printing out the scheduling report at the end of the window, will show up as an execution time spike on the first iteration of the subsequent measurement window. This can mask spikes caused by other components in the system. Defaults match the earlier settings hardcoded in code, so this commit has no functional change. Signed-off-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>
1 parent b826d6c commit 151e137

2 files changed

Lines changed: 52 additions & 5 deletions

File tree

src/schedule/Kconfig

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,3 +11,32 @@ config SCHEDULE_DMA_MULTI_CHANNEL
1111
default n
1212
help
1313
Enable multi-channel DMA scheduler
14+
15+
config SCHEDULE_LL_STATS_LOG
16+
bool "Log low-latency scheduler statistics"
17+
default y
18+
help
19+
Log statistics from low-latency scheduler. This is a low overhead
20+
mechanism to gather average and worst-case execution times of
21+
the low-latency scheduler invocations. A report is printed to
22+
logging subsystem (rate defined via SCHEDULE_LL_STATS_LOG_WINDOW_SIZE).
23+
24+
config SCHEDULE_LL_STATS_LOG_EVERY_OTHER_WINDOW
25+
bool "Log only every other low-latency report"
26+
depends on SCHEDULE_LL_STATS_LOG
27+
help
28+
Output statistics for every other statistics gathering window.
29+
This is useful to filter out impact of the reporting itself. With many
30+
logging implementations, the first iteration has a spike in
31+
execution caused by logging out results for the previous statistics
32+
window. By skipping every other window, the reporting overhead
33+
can be excluded.
34+
35+
config SCHEDULE_LL_STATS_LOG_WINDOW_SIZE
36+
int "Low latency statistics window size"
37+
default 10
38+
depends on SCHEDULE_LL_STATS_LOG
39+
help
40+
Size of the statistics window as a power of two. The window size
41+
setting also impacts the rate of reporting. With 1ms scheduler tick,
42+
default of 10 results in 1024msec window size.

src/schedule/zephyr_domain.c

Lines changed: 23 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -58,21 +58,38 @@ struct zephyr_domain {
5858
};
5959

6060
/* perf measurement windows size 2^x */
61-
#define CYCLES_WINDOW_SIZE 10
61+
#define CYCLES_WINDOW_SIZE CONFIG_SCHEDULE_LL_STATS_LOG_WINDOW_SIZE
62+
63+
#ifdef CONFIG_SCHEDULE_LL_STATS_LOG
64+
static inline void stats_report(unsigned int runs, int core, unsigned int cycles_sum,
65+
unsigned int cycles_max, unsigned int overruns)
66+
{
67+
#ifdef CONFIG_SCHEDULE_LL_STATS_LOG_EVERY_OTHER_WINDOW
68+
if (runs & BIT(CYCLES_WINDOW_SIZE))
69+
return;
70+
#endif
71+
tr_info(&ll_tr, "ll core %u timer avg %u, max %u, overruns %u",
72+
core, cycles_sum, cycles_max, overruns);
73+
}
74+
#endif /* CONFIG_SCHEDULE_LL_STATS_LOG */
6275

6376
static void zephyr_domain_thread_fn(void *p1, void *p2, void *p3)
6477
{
6578
struct zephyr_domain *zephyr_domain = p1;
6679
int core = cpu_get_id();
6780
struct zephyr_domain_thread *dt = zephyr_domain->domain_thread + core;
81+
#ifdef CONFIG_SCHEDULE_LL_STATS_LOG
6882
unsigned int runs = 0, overruns = 0, cycles_sum = 0, cycles_max = 0;
6983
unsigned int cycles0, cycles1, diff, timer_fired;
84+
#endif
7085

7186
for (;;) {
7287
/* immediately go to sleep, waiting to be woken up by the timer */
7388
k_sem_take(&dt->sem, K_FOREVER);
7489

90+
#ifdef CONFIG_SCHEDULE_LL_STATS_LOG
7591
cycles0 = k_cycle_get_32();
92+
#endif
7693

7794
#if CONFIG_CROSS_CORE_STREAM
7895
/*
@@ -95,6 +112,8 @@ static void zephyr_domain_thread_fn(void *p1, void *p2, void *p3)
95112
#endif
96113

97114
dt->handler(dt->arg);
115+
116+
#ifdef CONFIG_SCHEDULE_LL_STATS_LOG
98117
cycles1 = k_cycle_get_32();
99118

100119
/* This handles wrapping correctly too */
@@ -107,15 +126,14 @@ static void zephyr_domain_thread_fn(void *p1, void *p2, void *p3)
107126
cycles_sum += diff;
108127
cycles_max = diff > cycles_max ? diff : cycles_max;
109128

110-
if (++runs == 1 << CYCLES_WINDOW_SIZE) {
129+
if (!(++runs & MASK(CYCLES_WINDOW_SIZE - 1, 0))) {
111130
cycles_sum >>= CYCLES_WINDOW_SIZE;
112-
tr_info(&ll_tr, "ll core %u timer avg %u, max %u, overruns %u",
113-
core, cycles_sum, cycles_max, overruns);
131+
stats_report(runs, core, cycles_sum, cycles_max, overruns);
114132
cycles_sum = 0;
115133
cycles_max = 0;
116-
runs = 0;
117134
overruns = 0;
118135
}
136+
#endif /* CONFIG_SCHEDULE_LL_STATS_LOG */
119137

120138
/* Feed the watchdog */
121139
watchdog_feed(core);

0 commit comments

Comments
 (0)