Skip to content

ll_schedule: add a DSP load tracker to ll_tasks_execute #5407

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
lgirdwood merged 1 commit into from
Mar 23, 2022
Merged

ll_schedule: add a DSP load tracker to ll_tasks_execute #5407

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions Kconfig.sof
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -171,6 +171,15 @@ config DEBUG_IPC_COUNTERS
help
Select for enabling tracing IPC counter in SRAM_REG mailbox

config SCHEDULE_LOG_CYCLE_STATISTICS
bool "Log cycles per tick statistics for each task separately"
default y
help
Log DSP cycle usage statistics about once per second (1ms *
1024) for each task separately. The printed data is task's
meta information, average number of cycles/tick, and maximum
number of cycles/tick during the previous 1024 tick period.

config PERFORMANCE_COUNTERS
bool "Performance counters"
default n
Expand Down
2 changes: 2 additions & 0 deletions src/include/sof/schedule/task.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -69,6 +69,8 @@ struct task {
struct task_ops ops; /**< task operations */
#ifdef __ZEPHYR__
struct k_work_delayable z_delayed_work;
#endif
#if defined(CONFIG_SCHEDULE_LOG_CYCLE_STATISTICS) || defined(__ZEPHYR__)
uint32_t cycles_sum;
uint32_t cycles_max;
uint32_t cycles_cnt;
Expand Down
40 changes: 40 additions & 0 deletions src/schedule/ll_schedule.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,35 @@ static void schedule_ll_task_done(struct ll_schedule_data *sch,
atomic_read(&sch->domain->total_num_tasks));
}

/* perf measurement windows size 2^x */
#define CHECKS_WINDOW_SIZE 10

@marcinszkudlinski marcinszkudlinski Mar 7, 2022

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks to me as a debug feature,
once per second doesn't look very heavy, anyway i suggest putting it as an option in kconfig

@lgirdwood lgirdwood Mar 8, 2022

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jsarha can we give it the same Kconfig menu as the same feature that we have in the Zephyr LL scheduler i.e. the same Kconfig should enable them.
Can we also make the output trace message the same as Zephyr version too (using same units and strings) so that it's easy for developers to compare performance between xtos and Zephyr when optimising. Thanks.

@jsarha jsarha Mar 17, 2022

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have commit in my own repo for adding kconfig under Debug menu, but is that what you wanted? Or should it be without menu presence, and maybe in the schedule directory with changes?

@marcinszkudlinski marcinszkudlinski Mar 17, 2022

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we need to met a very aggressive power limitations and need to count every single cycle, so I think that if performance log is the only purpose for calculating CPU load, it should be off when there's no need for it (like in production). Unless there are other purposes?

@jsarha jsarha Mar 18, 2022

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There is now a Kconfig option, are you are happy with it? Can I resolve this conversation?


#ifdef CONFIG_SCHEDULE_LOG_CYCLE_STATISTICS
static inline void dsp_load_check(struct task *task, uint32_t cycles0, uint32_t cycles1)
{
uint32_t diff;

if (cycles1 > cycles0)
diff = cycles1 - cycles0;
else
diff = UINT32_MAX - cycles0 + cycles1;

task->cycles_sum += diff;

if (task->cycles_max < diff)
task->cycles_max = diff;

@mwasko mwasko Mar 17, 2022

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why max instead of peak? Max suggests range and here we clearly want to track 'peak' value in given timespan

@jsarha jsarha Mar 17, 2022 •
edited
Loading

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

*_peak was my name for variable before the per task implementation. With the per task implementation I decided to reuse the same struct task members as Zephyr side implementation does. The struct task members have different names.


if (++task->cycles_cnt == 1 << CHECKS_WINDOW_SIZE) {
task->cycles_sum >>= CHECKS_WINDOW_SIZE;
tr_info(&ll_tr, "task %p %pU avg %u, max %u", task, task->uid,
task->cycles_sum, task->cycles_max);
task->cycles_sum = 0;
task->cycles_max = 0;
task->cycles_cnt = 0;
}
}
#endif

static void schedule_ll_tasks_execute(struct ll_schedule_data *sch)
{
struct ll_schedule_domain *domain = sch->domain;
Expand All @@ -166,6 +195,9 @@ static void schedule_ll_tasks_execute(struct ll_schedule_data *sch)
* a pipeline task terminates a DMIC task.
*/
while (wlist != &sch->tasks) {
#ifdef CONFIG_SCHEDULE_LOG_CYCLE_STATISTICS
uint32_t cycles0, cycles1;
#endif
task = list_item(wlist, struct task, list);

if (task->state != SOF_TASK_STATE_PENDING) {
Expand All @@ -175,6 +207,9 @@ static void schedule_ll_tasks_execute(struct ll_schedule_data *sch)

tr_dbg(&ll_tr, "task %p %pU being started...", task, task->uid);

#ifdef CONFIG_SCHEDULE_LOG_CYCLE_STATISTICS
cycles0 = (uint32_t)k_cycle_get_64();
#endif
task->state = SOF_TASK_STATE_RUNNING;

/*
Expand All @@ -199,6 +234,11 @@ static void schedule_ll_tasks_execute(struct ll_schedule_data *sch)
}

k_spin_unlock(&domain->lock, key);

#ifdef CONFIG_SCHEDULE_LOG_CYCLE_STATISTICS
cycles1 = (uint32_t)k_cycle_get_64();
dsp_load_check(task, cycles0, cycles1);
#endif
}
}

Expand Down