Re: [PATCH v3] perf sched timehist: Add pre-migration wait time option

From: Madadi Vineeth Reddy
Date: Wed Oct 02 2024 - 23:08:20 EST


Hi Namhyung,

On 03/10/24 06:05, Namhyung Kim wrote:
> On Wed, Oct 02, 2024 at 10:09:17PM +0530, Madadi Vineeth Reddy wrote:
>> pre-migration wait time is the time that a task unnecessarily spends
>> on the runqueue of a CPU but doesn't get switched-in there. In terms
>> of tracepoints, it is the time between sched:sched_wakeup and
>> sched:sched_migrate_task.
>>

[snip]

>> @@ -2239,6 +2244,7 @@ static void timehist_update_runtime_stats(struct thread_runtime *r,
>
> It'd be nice if you update the comment on timehist_update_runtime_stats.
>
>
>> r->dt_iowait = 0;
>> r->dt_preempt = 0;
>> r->dt_run = 0;
>> + r->dt_pre_mig = 0;
>>
>> if (tprev) {
>> r->dt_run = t - tprev;
>> @@ -2247,6 +2253,11 @@ static void timehist_update_runtime_stats(struct thread_runtime *r,
>> pr_debug("time travel: wakeup time for task > previous sched_switch event\n");
>> else
>> r->dt_delay = tprev - r->ready_to_run;
>> +
>> + if (r->ready_to_run && r->migrated) {
>
> At this point r->read_to_run is not zero. And the r->migrated should
> not be zero when the below condition is met. So I think you can remove
> this condition.

You're right, my mistake. r->ready_to_run is already checked, and if
r->migrated is zero, it will naturally fail the condition below.

I've removed the redundant check and sent a v4. Thanks for the feedback!

Thanks,
Madadi Vineeth Reddy

>
> Thanks,
> Namhyung
>
>
>> + if ((r->migrated > r->ready_to_run) && (r->migrated < tprev))
>> + r->dt_pre_mig = r->migrated - r->ready_to_run;
>> + }
>> }
>>
>> if (r->last_time > tprev)
>> @@ -2270,6 +2281,7 @@ static void timehist_update_runtime_stats(struct thread_runtime *r,
>> r->total_sleep_time += r->dt_sleep;
>> r->total_iowait_time += r->dt_iowait;
>> r->total_preempt_time += r->dt_preempt;
>> + r->total_pre_mig_time += r->dt_pre_mig;
>> }
>>
>> static bool is_idle_sample(struct perf_sample *sample,
>> @@ -2684,8 +2696,14 @@ static int timehist_migrate_task_event(const struct perf_tool *tool,
>>
>> tr->migrations++;
>>
>> + if (tr->migrated == 0)
>> + tr->migrated = sample->time;
>> +
>> /* show migrations if requested */
>> - timehist_print_migration_event(sched, evsel, sample, machine, thread);
>> + if (sched->show_migrations) {
>> + timehist_print_migration_event(sched, evsel, sample,
>> + machine, thread);
>> + }
>>
>> return 0;
>> }
>> @@ -2836,11 +2854,13 @@ static int timehist_sched_change_event(const struct perf_tool *tool,
>> /* last state is used to determine where to account wait time */
>> tr->last_state = state;
>>
>> - /* sched out event for task so reset ready to run time */
>> + /* sched out event for task so reset ready to run time and migrated time */
>> if (state == 'R')
>> tr->ready_to_run = t;
>> else
>> tr->ready_to_run = 0;
>> +
>> + tr->migrated = 0;
>> }
>>
>> evsel__save_time(evsel, sample->time, sample->cpu);
>> @@ -3280,8 +3300,8 @@ static int perf_sched__timehist(struct perf_sched *sched)
>> goto out;
>> }
>>
>> - if (sched->show_migrations &&
>> - perf_session__set_tracepoints_handlers(session, migrate_handlers))
>> + if ((sched->show_migrations || sched->pre_migrations) &&
>> + perf_session__set_tracepoints_handlers(session, migrate_handlers))
>> goto out;
>>
>> /* pre-allocate struct for per-CPU idle stats */
>> @@ -3823,6 +3843,7 @@ int cmd_sched(int argc, const char **argv)
>> OPT_BOOLEAN(0, "show-prio", &sched.show_prio, "Show task priority"),
>> OPT_STRING(0, "prio", &sched.prio_str, "prio",
>> "analyze events only for given task priority(ies)"),
>> + OPT_BOOLEAN('P', "pre-migrations", &sched.pre_migrations, "Show pre-migration wait time"),
>> OPT_PARENT(sched_options)
>> };
>>
>> --
>> 2.43.2
>>