linux-kernel - RE: [PATCH v2] perf sched timehist: Fixed timestamp error when unable to confirm event sched

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [day] [month] [year] [list]

Message-ID: <ab337b83-ac74-43ce-83f0-25885c136574@linux.ibm.com>
Date: Wed, 21 Aug 2024 15:58:15 +0530
From: Madadi Vineeth Reddy <vineethr@...ux.ibm.com>
To: yangjihong <yangjihong@...edance.com>
Cc: peterz@...radead.org, mingo@...hat.com, acme@...nel.org,
        namhyung@...nel.org, mark.rutland@....com,
        alexander.shishkin@...ux.intel.com, jolsa@...nel.org,
        irogers@...gle.com, adrian.hunter@...el.com, kan.liang@...ux.intel.com,
        james.clark@....com, linux-perf-users@...r.kernel.org,
        linux-kernel@...r.kernel.org,
        Madadi Vineeth Reddy <vineethr@...ux.ibm.com>
Subject: RE: [PATCH v2] perf sched timehist: Fixed timestamp error when unable to
 confirm event sched_in time

Hi Yang Jihong,

On 21/08/24 11:46, yangjihong wrote:
> Hello,
> 
> On 2024/8/21 2:00, Madadi Vineeth Reddy wrote:
>> Hi Yang Jihong,
>>
>> On 19/08/24 08:17, Yang Jihong wrote:
>>> If sched_in event for current task is not recorded, sched_in timestamp
>>> will be set to end_time of time window interest, causing an error in
>>> timestamp show. In this case, we choose to ignore this event.
>>>
>>
>> Why sched-in is not happening for the perf task continuously
>>
>> perf sched record -a sleep 5
>>
>> perf sched script
>> perf 19593 [000] 42668.450179: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=69449 [ns] vruntime=7303687 [ns]
>> perf 19593 [000] 42668.450190: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=6039 [ns] vruntime=7309726 [ns]
>> perf 19593 [000] 42668.450191: sched:sched_waking: comm=migration/0
> pid=19 prio=0 target_cpu=000
>> perf 19593 [000] 42668.450192: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=2397 [ns] vruntime=7312123 [ns]
>> perf 19593 [000] 42668.450193: sched:sched_switch: perf:19593 [120] R ==>
> migration/0:19 [0]
>> migration/0 19 [000] 42668.450195: sched:sched_migrate_task: comm=perf
> pid=19593 prio=120 orig_cpu=0 dest_cpu=1
>> migration/0 19 [000] 42668.450200: sched:sched_switch: migration/0:19 [0]
> S ==> swapper/0:0 [120]
>> perf 19593 [001] 42668.450308: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=112515 [ns] vruntime=9972397 [ns]
>> perf 19593 [001] 42668.450311: sched:sched_waking: comm=migration/1
> pid=24 prio=0 target_cpu=001
>> perf 19593 [001] 42668.450313: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=4690 [ns] vruntime=9977087 [ns]
>> perf 19593 [001] 42668.450314: sched:sched_switch: perf:19593 [120] R ==>
> migration/1:24 [0]
>> migration/1 24 [001] 42668.450316: sched:sched_migrate_task: comm=perf
> pid=19593 prio=120 orig_cpu=1 dest_cpu=2
>> migration/1 24 [001] 42668.450322: sched:sched_switch: migration/1:24 [0]
> S ==> swapper/1:0 [120]
>> perf 19593 [002] 42668.450385: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=67379 [ns] vruntime=2885994 [ns]
>> perf 19593 [002] 42668.450389: sched:sched_waking: comm=migration/2
> pid=30 prio=0 target_cpu=002
>> perf 19593 [002] 42668.450391: sched:sched_stat_runtime: comm=perf
> pid=19593 runtime=5526 [ns] vruntime=2891520 [ns]
>> perf 19593 [002] 42668.450392: sched:sched_switch: perf:19593 [120] R ==>
> migration/2:30 [0]
>>
>> The perf task (PID 19593) is being switched out without being switched in
> after CPU migration. The task migrates to a different CPU,
>> and then immediately switches out without a sched_in event in between.
>>
> Because the perf tool sets CPU affinity first (which causes perf process
> to migrate to the target core) and then enables events, by the time
> starts recording, task is likely to have migrated to the target core and
> started running. In this case, the sched_in event is not recorded.
> 

Got it. Thanks for the explanation!

Thanks and Regards
Madadi Vineeth Reddy

> Thanks,
> Yang
>