kernel.git/tools/perf/builtin-stat.c, branch linux-4.18.y

perf stat: Fix --interval_clear option

2018-07-11T13:43:03Z

Currently we display extra header line, like: # perf stat -I 1000 -a --interval-clear # time counts unit events insn per cycle branch-misses of all branches 2.964917103 3855.349912 cpu-clock (msec) # 3.855 CPUs utilized 2.964917103 23,993 context-switches # 0.006 M/sec 2.964917103 1,301 cpu-migrations # 0.329 K/sec ... Fixing the condition and getting proper: # perf stat -I 1000 -a --interval-clear # time counts unit events 2.359048938 1432.492228 cpu-clock (msec) # 1.432 CPUs utilized 2.359048938 7,613 context-switches # 0.002 M/sec 2.359048938 419 cpu-migrations # 0.133 K/sec ... Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Fixes: 9660e08ee8cb ("perf stat: Add --interval-clear option") Link: http://lkml.kernel.org/r/20180702134202.17745-2-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Add event parsing error handling to add_default_attributes

2018-06-07T19:03:21Z

Add missing error handling for parse_events calls in add_default_attributes functions. The error handler displays error details, like for transactions (-T): Before: $ perf stat -T Cannot set up transaction events After: $ perf stat -T Cannot set up transaction events event syntax error: '..cycles,cpu/cycles-t/,cpu/tx-start/,cpu/el-start/,cpu/cycles-ct/}' \___ unknown term Signed-off-by: Jiri Olsa Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Frederic Weisbecker Cc: Milian Wolff Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/r/20180606221513.11302-8-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Allow to specify specific metric column len

2018-06-07T19:01:44Z

The following change will introduce new metrics, that doesn't need such wide hard coded spacing. Switch METRIC_ONLY_LEN macro usage with metric_only_len variable. Signed-off-by: Jiri Olsa Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Frederic Weisbecker Cc: Milian Wolff Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/r/20180606221513.11302-7-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Fix metric column header display alignment

2018-06-07T18:59:13Z

Make the metric only display aligned. Before: # perf stat --topdown -I 1000 # time core cpus retiring bad speculation frontend bound backend bound 1.000394323 S0-C0 2 37.4% 12.0% 31.4% 19.2% 1.000394323 S0-C1 2 25.1% 9.2% 43.8% 21.9% 2.001521204 S0-C0 2 36.4% 11.4% 32.4% 19.8% 2.001521204 S0-C1 2 26.2% 9.4% 43.1% 21.3% 3.001930208 S0-C0 2 35.1% 10.7% 33.6% 20.6% 3.001930208 S0-C1 2 28.9% 10.0% 40.0% 21.1% After: # perf stat --topdown -I 1000 # time core cpus retiring bad speculation frontend bound backend bound 1.000303722 S0-C0 2 34.2% 7.6% 34.2% 24.0% 1.000303722 S0-C1 2 33.1% 6.4% 36.9% 23.6% 2.001281055 S0-C0 2 34.6% 6.7% 36.8% 21.8% 2.001281055 S0-C1 2 32.8% 7.1% 38.1% 22.0% 3.001546080 S0-C0 2 39.3% 5.5% 32.7% 22.5% 3.001546080 S0-C1 2 37.8% 6.0% 33.1% 23.1% Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Frederic Weisbecker Cc: Milian Wolff Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/r/20180606221513.11302-6-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Use only color_fprintf call in print_metric_only

2018-06-07T18:58:13Z

We can call color_fprintf also for non color case, it's handled properly. This change simplifies following patch. Signed-off-by: Jiri Olsa Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Frederic Weisbecker Cc: Milian Wolff Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/r/20180606221513.11302-5-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Add --interval-clear option

2018-06-07T18:53:36Z

Adding --interval-clear option to clear the screen before next interval. Committer testing: # perf stat -I 1000 --interval-clear And, as expected, it behaves almost like: # watch -n 0 perf stat -a sleep 1 Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Frederic Weisbecker Cc: Milian Wolff Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Stephane Eranian Link: http://lkml.kernel.org/r/20180606221513.11302-4-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Display user and system time

2018-06-06T15:52:04Z

Adding the support to read rusage data once the workload is finished and display the system/user time values: $ perf stat --null perf bench sched pipe ... Performance counter stats for 'perf bench sched pipe': 5.342599256 seconds time elapsed 2.544434000 seconds user 4.549691000 seconds sys It works only in non -r mode and only for workload target. So as of now, for workload targets, we display 3 types of timings. The time we meassure in perf stat from enable to disable+period: 5.342599256 seconds time elapsed The time spent in user and system lands, displayed only for workload session/target: 2.544434000 seconds user 4.549691000 seconds sys Those times are the very same displayed by 'time' tool. They are returned by wait4 call via the getrusage struct interface. Committer notes: Had to rename some variables to avoid this on older systems such as centos:6: builtin-stat.c: In function 'print_footer': builtin-stat.c:1831: warning: declaration of 'stime' shadows a global declaration /usr/include/time.h:297: warning: shadowed declaration is here Committer testing: # perf stat --null time perf bench sched pipe # Running 'sched/pipe' benchmark: # Executed 1000000 pipe operations between two processes Total time: 5.526 [sec] 5.526534 usecs/op 180945 ops/sec 1.00user 6.25system 0:05.52elapsed 131%CPU (0avgtext+0avgdata 8056maxresident)k 0inputs+0outputs (0major+606minor)pagefaults 0swaps Performance counter stats for 'time perf bench sched pipe': 5.530978744 seconds time elapsed 1.004037000 seconds user 6.259937000 seconds sys # Suggested-by: Ingo Molnar Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180605121313.31337-1-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Display length strings of each run for --table option

2018-04-26T12:30:27Z

Adding support to display visual aid 'length strings' to easily spot the biggest difference in time table. $ perf stat -r 10 --table perf bench sched pipe ... Performance counter stats for './perf bench sched pipe' (5 runs): # Table of individual measurements: 5.189 (-0.293) # 5.189 (-0.294) # 5.186 (-0.296) # 5.663 (+0.181) ## 6.186 (+0.703) #### # Final result: 5.483 +- 0.198 seconds time elapsed ( +- 3.62% ) Suggested-by: Ingo Molnar Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180423090823.32309-9-jolsa@kernel.org [ Updated 'perf stat --table' man page entry ] Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Add --table option to display time of each run

2018-04-26T12:30:27Z

Add --table option to display time for each run (-r option), like: $ perf stat --null -r 5 --table perf bench sched pipe Performance counter stats for './perf bench sched pipe' (5 runs): # Table of individual measurements: 5.379 (-0.176) 5.243 (-0.311) 5.238 (-0.317) 5.536 (-0.019) 6.377 (+0.823) # Final result: 5.555 +- 0.213 seconds time elapsed ( +- 3.83% ) Suggested-by: Ingo Molnar Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180423090823.32309-8-jolsa@kernel.org [ Document the new option in 'perf stat's man page ] Signed-off-by: Arnaldo Carvalho de Melo

perf stat: Display time in precision based on std deviation

2018-04-26T12:30:27Z

Ingo suggested to display elapsed time for multirun workload (perf stat -e) with precision based on the precision of the standard deviation. In his own words: > This output is a slightly bit misleading: > Performance counter stats for 'make -j128' (10 runs): > 27.988995256 seconds time elapsed ( +- 0.39% ) > The 9 significant digits in the result, while only 1 is valid, suggests accuracy > where none exists. > It would be better if 'perf stat' would display elapsed time with a precision > adjusted to stddev, it should display at most 2 more significant digits than > the stddev inaccuracy. > I.e. in the above case 0.39% is 0.109, so we only have accuracy for 1 digit, and > so we should only display 3: > 27.988 seconds time elapsed ( +- 0.39% ) Plus a suggestion about the output, which is small enough and connected with the above change that I merged both changes together. > Small output style nit - I think it would be nice if with --repeat the stddev was > also displayed in absolute values, besides percentage: > > 27.988 +- 0.109 seconds time elapsed ( +- 0.39% ) The output is now: Performance counter stats for './perf bench sched pipe' (5 runs): SNIP 13.3667 +- 0.0256 seconds time elapsed ( +- 0.19% ) Suggested-by: Ingo Molnar Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: Andi Kleen Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180423090823.32309-7-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo