linux-kernel - Re: [PATCH v2] perf stat: Improve runtime stat for interval mode

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>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Wed, 22 Apr 2020 08:53:41 +0800
From:   "Jin, Yao" <yao.jin@...ux.intel.com>
To:     Arnaldo Carvalho de Melo <arnaldo.melo@...il.com>
Cc:     jolsa@...nel.org, peterz@...radead.org, mingo@...hat.com,
        alexander.shishkin@...ux.intel.com, Linux-kernel@...r.kernel.org,
        ak@...ux.intel.com, kan.liang@...el.com, yao.jin@...el.com
Subject: Re: [PATCH v2] perf stat: Improve runtime stat for interval mode

Hi Arnaldo,

On 4/21/2020 9:53 PM, Arnaldo Carvalho de Melo wrote:
> Em Mon, Apr 20, 2020 at 10:54:17PM +0800, Jin Yao escreveu:
>> For interval mode, the metric is printed after # if it exists. But
>> it's not calculated by the counts generated in this interval. See
>> following examples,
>>
>>   root@...-ppc:~# perf stat -M CPI -I1000 --interval-count 2
>>   #           time             counts unit events
>>        1.000422803            764,809      inst_retired.any          #      2.9 CPI
>>        1.000422803          2,234,932      cycles
>>        2.001464585          1,960,061      inst_retired.any          #      1.6 CPI
>>        2.001464585          4,022,591      cycles
>>
>> The second CPI should not be 1.6 (4,022,591/1,960,061 is 2.1)
>>
>>   root@...-ppc:~# perf stat -e cycles,instructions -I1000 --interval-count 2
>>   #           time             counts unit events
>>        1.000429493          2,869,311      cycles
>>        1.000429493            816,875      instructions              #    0.28  insn per cycle
>>        2.001516426          9,260,973      cycles
>>        2.001516426          5,250,634      instructions              #    0.87  insn per cycle
>>
>> The second 'insn per cycle' should not be 0.87 (5,250,634/9,260,973 is 0.57).
>>
>> The current code uses a global variable rt_stat for tracking and
>> updating the std dev of runtime stat. Unlike the counts, rt_stat is
>> not reset for interval. While the counts are reset for interval.
>>
>> perf_stat_process_counter()
>> {
>>          if (config->interval)
>>                  init_stats(ps->res_stats);
>> }
>>
>> So for interval, the rt_stat should be reset either.
> 
>                                s/either/too/g right?
> 

Yes, should use "too" here. :)

> And please try and find what was the cset that introduced the problem,
> so that we can have a Fixes: line and the stable series can pick it, ok?
 >
> - Arnaldo
>

I have tried to find the patch which introduced this issue.

51fd2df1e882 ("perf stat: Fix interval output values").

This patch zeros stats for interval mode. I just think it should reset 
rt_stat too.

But I really don't know if it's fair to this patch so I don't add it in 
my patch description.

Thanks
Jin Yao

>> This patch resets rt_stat before read_counters, so the runtime
>> stat is only calculated by the counts generated in this interval.
>>
>> With this patch,
>>
>>   root@...-ppc:~# perf stat -M CPI -I1000 --interval-count 2
>>   #           time             counts unit events
>>        1.000420924          2,408,818      inst_retired.any          #      2.1 CPI
>>        1.000420924          5,010,111      cycles
>>        2.001448579          2,798,407      inst_retired.any          #      1.6 CPI
>>        2.001448579          4,599,861      cycles
>>
>>   root@...-ppc:~# perf stat -e cycles,instructions -I1000 --interval-count 2
>>   #           time             counts unit events
>>        1.000428555          2,769,714      cycles
>>        1.000428555            774,462      instructions              #    0.28  insn per cycle
>>        2.001471562          3,595,904      cycles
>>        2.001471562          1,243,703      instructions              #    0.35  insn per cycle
>>
>> Now the second 'insn per cycle' and CPI are calculated by the counts
>> generated in this interval.
>>
>>   v2:
>>   ---
>>   Use just existing perf_stat__reset_shadow_per_stat(&rt_stat).
>>   We don't need to define new function perf_stat__reset_rt_stat.
>>
>> Signed-off-by: Jin Yao <yao.jin@...ux.intel.com>
>> ---
>>   tools/perf/Documentation/perf-stat.txt | 2 ++
>>   tools/perf/builtin-stat.c              | 1 +
>>   2 files changed, 3 insertions(+)
>>
>> diff --git a/tools/perf/Documentation/perf-stat.txt b/tools/perf/Documentation/perf-stat.txt
>> index 4d56586b2fb9..3fb5028aef08 100644
>> --- a/tools/perf/Documentation/perf-stat.txt
>> +++ b/tools/perf/Documentation/perf-stat.txt
>> @@ -176,6 +176,8 @@ Print count deltas every N milliseconds (minimum: 1ms)
>>   The overhead percentage could be high in some cases, for instance with small, sub 100ms intervals.  Use with caution.
>>   	example: 'perf stat -I 1000 -e cycles -a sleep 5'
>>   
>> +If the metric exists, it is calculated by the counts generated in this interval and the metric is printed after #.
>> +
>>   --interval-count times::
>>   Print count deltas for fixed number of times.
>>   This option should be used together with "-I" option.
>> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
>> index 9207b6c45475..3f050d85c277 100644
>> --- a/tools/perf/builtin-stat.c
>> +++ b/tools/perf/builtin-stat.c
>> @@ -359,6 +359,7 @@ static void process_interval(void)
>>   	clock_gettime(CLOCK_MONOTONIC, &ts);
>>   	diff_timespec(&rs, &ts, &ref_time);
>>   
>> +	perf_stat__reset_shadow_per_stat(&rt_stat);
>>   	read_counters(&rs);
>>   
>>   	if (STAT_RECORD) {
>> -- 
>> 2.17.1
>>
>