Re: [PATCH v2 0/7] Perf stat --null/offline CPU segv related fixes/tests

[Ingo Molnar <mingo@kernel.org>]

* Ian Rogers <irogers@google.com> wrote:

> > There's one more perf stat QoL bug I'd like to report - I frequently
> > do repeated runs of perf stat --repeat and grep the output, to get
> > a feel for the run-to-run stability of a particular benchmark:
> >
> >   starship:~/tip> while :; do perf stat --null --repeat 3 sleep 0.1 2>&1 | grep elapsed; done
> >          0.1017997 +- 0.0000771 seconds time elapsed  ( +-  0.08% )
> >          0.1017627 +- 0.0000795 seconds time elapsed  ( +-  0.08% )
> >          0.1018106 +- 0.0000650 seconds time elapsed  ( +-  0.06% )
> >          0.1017844 +- 0.0000601 seconds time elapsed  ( +-  0.06% )
> >           0.101883 +- 0.000169 seconds time elapsed  ( +-  0.17% ) <====
> >          0.1017757 +- 0.0000532 seconds time elapsed  ( +-  0.05% )
> >          0.1017991 +- 0.0000720 seconds time elapsed  ( +-  0.07% )
> >          0.1018024 +- 0.0000704 seconds time elapsed  ( +-  0.07% )
> >          0.1018074 +- 0.0000946 seconds time elapsed  ( +-  0.09% )
> >          0.1019797 +- 0.0000524 seconds time elapsed  ( +-  0.05% )
> >          0.1018407 +- 0.0000658 seconds time elapsed  ( +-  0.06% )
> >          0.1017907 +- 0.0000605 seconds time elapsed  ( +-  0.06% )
> >          0.1018328 +- 0.0000868 seconds time elapsed  ( +-  0.09% )
> >          0.1017469 +- 0.0000285 seconds time elapsed  ( +-  0.03% )
> >          0.1019589 +- 0.0000549 seconds time elapsed  ( +-  0.05% )
> >          0.1018465 +- 0.0000891 seconds time elapsed  ( +-  0.09% )
> >           0.101868 +- 0.000117 seconds time elapsed  ( +-  0.12% ) <====
> >          0.1017705 +- 0.0000590 seconds time elapsed  ( +-  0.06% )
> >          0.1017728 +- 0.0000718 seconds time elapsed  ( +-  0.07% )
> >          0.1017821 +- 0.0000419 seconds time elapsed  ( +-  0.04% )
> >          0.1018328 +- 0.0000581 seconds time elapsed  ( +-  0.06% )
> >          0.1017836 +- 0.0000853 seconds time elapsed  ( +-  0.08% )
> >          0.1018124 +- 0.0000765 seconds time elapsed  ( +-  0.08% )
> >          0.1018706 +- 0.0000639 seconds time elapsed  ( +-  0.06% )
> >
> > Note the two outliers, which happen due to some misguided
> > output optimization feature in perf shortening zero-ended
> > numbers unnecessarily, and adding noise to the grepped
> > output's vertical alignment.
> >
> > Those two lines should be:
> >
> >          0.1017844 +- 0.0000601 seconds time elapsed  ( +-  0.06% )
> >          0.1018830 +- 0.0001690 seconds time elapsed  ( +-  0.17% ) <====
> >          0.1017757 +- 0.0000532 seconds time elapsed  ( +-  0.05% )
> >
> >          0.1018465 +- 0.0000891 seconds time elapsed  ( +-  0.09% )
> >          0.1018680 +- 0.0001170 seconds time elapsed  ( +-  0.12% ) <====
> >          0.1017705 +- 0.0000590 seconds time elapsed  ( +-  0.06% )
> >
> > (The zeroes are printed fully, to full precision.)
> >
> > Basically random chance causing an apparent lack of significant
> > numbers doesn't mean the tool should strip them from the output.
>
> Ugh. I'm not sure why the output is like that.

Yeah, I'm sure some dim-witted kernel developer requested it,
without thinking through all the consequences.

> [...] Searching back through history it seems you are to blame :-)
> https://web.git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next.git/commit/tools/perf/builtin-stat.c?h=perf-tools-next&id=bc22de9bcdb2249150fb5b3c48fdc4f6bedd3ad7

Uhm, never mind, what a brilliant feature! ;-)

> Perhaps we can drop the precision printf flag and just make the flags
> fixed. I think this output is obscure enough that nobody cares about
> minor changes.

Yeah, sounds good.

Thanks,

	Ingo