perf script: Add min, max to futex-contention output, in addition to avg

Average is quite informative, but the outliners - especially max - are
also of interest.

Before:

  mutex-locker[793299] lock 5637ec61e080 contended 3400 times, 446 avg ns
  mutex-locker[793301] lock 5637ec61e080 contended 3563 times, 385 avg ns
  mutex-locker[793300] lock 5637ec61e080 contended 3110 times, 1855 avg ns

After:

  mutex-locker[795251] lock 55b14e6dd080 contended 3853 times, 1279 avg ns [max: 12270 ns, min 340 ns]
  mutex-locker[795253] lock 55b14e6dd080 contended 2911 times, 518 avg ns [max: 51660261 ns, min 347 ns]
  mutex-locker[795252] lock 55b14e6dd080 contended 3843 times, 385 avg ns [max: 24323998 ns, min 338 ns]

Committer testing:

  [root@five ~]# perf script record futex-contention -a
  ^C[ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 1.877 MB perf.data (923 samples) ]

  [root@five ~]# perf evlist
  syscalls:sys_enter_futex
  syscalls:sys_exit_futex
  dummy:HG
  # Tip: use 'perf evlist --trace-fields' to show fields for tracepoint events
  #

Before:

  [root@five ~]# perf script report futex-contention
  JS Helper[2457] lock 55fe0cf82610 contended 4 times, 6657 avg ns
  ibus-daemon[2975] lock 56227f6d0210 contended 4 times, 1020 avg ns
  chromium-browse[1905801] lock 7ffe573f5088 contended 8 times, 108463 avg ns
  gnome-shell[2240] lock 55fe0cf82678 contended 1 times, 8616 avg ns
  gnome-shel:cs0[2292] lock 55fe0d0ab768 contended 3 times, 606016034 avg ns
  JS Helper[2458] lock 55fe0cf82690 contended 1 times, 1167840 avg ns
  chromium-browse[1905470] lock 7ffe573f5358 contended 1 times, 551504 avg ns
  chromium-browse[1905948] lock 7ffe573f5358 contended 1 times, 577422 avg ns
  gnome-shell[2240] lock 55fe0cf82660 contended 6 times, 202696 avg ns
  pool[2602] lock 7fd600008ef0 contended 1 times, 500046007 avg ns
  chromium-browse[1905801] lock 7ffe573f5128 contended 4 times, 285083 avg ns
  JS Helper[2460] lock 55fe0cf82690 contended 1 times, 680877 avg ns
  JS Helper[2459] lock 55fe0cf82610 contended 7 times, 4224 avg ns
  chromium-browse[1905434] lock 7ffe573f5358 contended 1 times, 697038 avg ns
  chromium-browse[212592] lock 7ffe573f53c8 contended 4 times, 460601 avg ns
  gnome-shel:cs0[2292] lock 55fe0d0ab76c contended 2 times, 601237648 avg ns
  JS Helper[2460] lock 55fe0cf82610 contended 4 times, 3340 avg ns
  JS Helper[2462] lock 55fe0cf82694 contended 1 times, 237275 avg ns
  chromium-browse[1905605] lock 7ffe573f5358 contended 2 times, 634555 avg ns
  chromium-browse[1905992] lock 7ffe573f5358 contended 1 times, 583965 avg ns
  chromium-browse[1905647] lock 7ffe573f5368 contended 8 times, 549800 avg ns
  JS Helper[2462] lock 55fe0cf82610 contended 2 times, 4694 avg ns
  JS Helper[2461] lock 55fe0cf82694 contended 1 times, 257793 avg ns
  JS Helper[2456] lock 55fe0cf82690 contended 1 times, 677771 avg ns
  JS Helper[2463] lock 55fe0cf82610 contended 3 times, 5139 avg ns
  gdbus[2980] lock 56227f6d0210 contended 2 times, 2465 avg ns
  gnome-shell[2240] lock 55fe0cf82664 contended 5 times, 8036 avg ns
  chromium-browse[1906308] lock 7ffe573f5358 contended 1 times, 210735 avg ns
  JS Helper[2463] lock 55fe0cf82694 contended 1 times, 251531 avg ns
  chromium-browse[1905801] lock 7ffe573f4f58 contended 4 times, 399927 avg ns
  [root@five ~]#

After:

  [root@five ~]# perf script report futex-contention
  JS Helper[2457] lock 55fe0cf82610 contended 4 times, 6657 avg ns [max: 11502 ns, min 792 ns]
  ibus-daemon[2975] lock 56227f6d0210 contended 4 times, 1020 avg ns [max: 1813 ns, min 581 ns]
  chromium-browse[1905801] lock 7ffe573f5088 contended 8 times, 108463 avg ns [max: 380103 ns, min 57989 ns]
  gnome-shell[2240] lock 55fe0cf82678 contended 1 times, 8616 avg ns [max: 8616 ns, min 8616 ns]
  gnome-shel:cs0[2292] lock 55fe0d0ab768 contended 3 times, 606016034 avg ns [max: 611295960 ns, min 600191357 ns]
  JS Helper[2458] lock 55fe0cf82690 contended 1 times, 1167840 avg ns [max: 1167840 ns, min 1167840 ns]
  chromium-browse[1905470] lock 7ffe573f5358 contended 1 times, 551504 avg ns [max: 551504 ns, min 551504 ns]
  chromium-browse[1905948] lock 7ffe573f5358 contended 1 times, 577422 avg ns [max: 577422 ns, min 577422 ns]
  gnome-shell[2240] lock 55fe0cf82660 contended 6 times, 202696 avg ns [max: 398998 ns, min 5050 ns]
  pool[2602] lock 7fd600008ef0 contended 1 times, 500046007 avg ns [max: 500046007 ns, min 500046007 ns]
  chromium-browse[1905801] lock 7ffe573f5128 contended 4 times, 285083 avg ns [max: 389531 ns, min 76183 ns]
  JS Helper[2460] lock 55fe0cf82690 contended 1 times, 680877 avg ns [max: 680877 ns, min 680877 ns]
  JS Helper[2459] lock 55fe0cf82610 contended 7 times, 4224 avg ns [max: 12724 ns, min 1012 ns]
  chromium-browse[1905434] lock 7ffe573f5358 contended 1 times, 697038 avg ns [max: 697038 ns, min 697038 ns]
  chromium-browse[212592] lock 7ffe573f53c8 contended 4 times, 460601 avg ns [max: 594956 ns, min 232996 ns]
  gnome-shel:cs0[2292] lock 55fe0d0ab76c contended 2 times, 601237648 avg ns [max: 601255863 ns, min 601219434 ns]
  JS Helper[2460] lock 55fe0cf82610 contended 4 times, 3340 avg ns [max: 9168 ns, min 962 ns]
  JS Helper[2462] lock 55fe0cf82694 contended 1 times, 237275 avg ns [max: 237275 ns, min 237275 ns]
  chromium-browse[1905605] lock 7ffe573f5358 contended 2 times, 634555 avg ns [max: 1024060 ns, min 245050 ns]
  chromium-browse[1905992] lock 7ffe573f5358 contended 1 times, 583965 avg ns [max: 583965 ns, min 583965 ns]
  chromium-browse[1905647] lock 7ffe573f5368 contended 8 times, 549800 avg ns [max: 775293 ns, min 258375 ns]
  JS Helper[2462] lock 55fe0cf82610 contended 2 times, 4694 avg ns [max: 8556 ns, min 832 ns]
  JS Helper[2461] lock 55fe0cf82694 contended 1 times, 257793 avg ns [max: 257793 ns, min 257793 ns]
  JS Helper[2456] lock 55fe0cf82690 contended 1 times, 677771 avg ns [max: 677771 ns, min 677771 ns]
  JS Helper[2463] lock 55fe0cf82610 contended 3 times, 5139 avg ns [max: 6873 ns, min 931 ns]
  gdbus[2980] lock 56227f6d0210 contended 2 times, 2465 avg ns [max: 4188 ns, min 742 ns]
  gnome-shell[2240] lock 55fe0cf82664 contended 5 times, 8036 avg ns [max: 13105 ns, min 401 ns]
  chromium-browse[1906308] lock 7ffe573f5358 contended 1 times, 210735 avg ns [max: 210735 ns, min 210735 ns]
  JS Helper[2463] lock 55fe0cf82694 contended 1 times, 251531 avg ns [max: 251531 ns, min 251531 ns]
  chromium-browse[1905801] lock 7ffe573f4f58 contended 4 times, 399927 avg ns [max: 476904 ns, min 178495 ns]
  [root@five ~]#

Signed-off-by: Hagen Paul Pfeifer <hagen@jauu.net>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Link: http://lore.kernel.org/lkml/20200922200922.1306034-1-hagen@jauu.net
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

1 files changed, 2 insertions, 2 deletions

diff --git a/tools/perf/scripts/python/futex-contention.py b/tools/perf/scripts/python/futex-contention.py
index c440f02627dd..7e884d46f920 100644
--- a/tools/perf/scripts/python/futex-contention.py
+++ b/tools/perf/scripts/python/futex-contention.py
@@ -53,5 +53,5 @@ def trace_begin():
 def trace_end():
     for (tid, lock) in lock_waits:
         min, max, avg, count = lock_waits[tid, lock]
-        print("%s[%d] lock %x contended %d times, %d avg ns" %
-              (process_names[tid], tid, lock, count, avg))
+        print("%s[%d] lock %x contended %d times, %d avg ns [max: %d ns, min %d ns]" %
+              (process_names[tid], tid, lock, count, avg, max, min))