linux-perf-users.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Milian Wolff <milian.wolff@kdab.com>
To: "linux-perf-users@vger.kernel.org" <linux-perf-users@vger.kernel.org>
Subject: Re: Reordering the thread output in perf trace --summary
Date: Wed, 04 May 2016 11:51:04 +0200	[thread overview]
Message-ID: <52227896.H02DnUL2Ue@milian-kdab2> (raw)
In-Reply-To: <91397949.qTd2kn5sDj@milian-kdab2>

[-- Attachment #1: Type: text/plain, Size: 6376 bytes --]

On Wednesday, May 4, 2016 11:02:12 AM CEST Milian Wolff wrote:
> Hey all,
> 
> when using `perf trace --summary` on a (badly designed) user application
> that creates tons of threads, the usually interesting overall summary is
> drowned by the per-thread summary output. I.e.:
> 
> perf trace --summary lab_mandelbrot_concurrent |& grep events
>  lab_mandelbrot_ (19497), 9246 events, 25.7%, 0.000 msec
>  QXcbEventReader (19498), 1094 events, 3.0%, 0.000 msec
>  QDBusConnection (19499), 132 events, 0.4%, 0.000 msec
>  Thread (pooled) (19500), 1982 events, 5.5%, 0.000 msec
>  Thread (pooled) (19501), 114 events, 0.3%, 0.000 msec
>  lab_mandelbrot_ (19502), 88 events, 0.2%, 0.000 msec
>  Thread (pooled) (19503), 106 events, 0.3%, 0.000 msec
>  Thread (pooled) (19504), 101 events, 0.3%, 0.000 msec
>  Thread (pooled) (19505), 102 events, 0.3%, 0.000 msec
> ... continued for a total of 163 lines
> 
> usually, I forget to pipe the output of `perf trace --summary` into a file
> and then have to rerun the command, as the total output (2643 lines!)
> easily exceeds my scrollback buffer.
> 
> I would like to propose to reorder the output to sort the output in
> ascending total event order, such that the most interesting output is shown
> at the bottom of the output on the CLI. I.e. in the output above it should
> be something like
> 
> perf trace --summary lab_mandelbrot_concurrent |& grep events
> ... continued for a total of 163 lines
>  lab_mandelbrot_ (19502), 88 events, 0.2%, 0.000 msec
>  Thread (pooled) (19501), 114 events, 0.3%, 0.000 msec
>  Thread (pooled) (19503), 106 events, 0.3%, 0.000 msec
>  Thread (pooled) (19504), 101 events, 0.3%, 0.000 msec
>  Thread (pooled) (19505), 102 events, 0.3%, 0.000 msec
>  QDBusConnection (19499), 132 events, 0.4%, 0.000 msec
>  QXcbEventReader (19498), 1094 events, 3.0%, 0.000 msec
>  Thread (pooled) (19500), 1982 events, 5.5%, 0.000 msec
>  lab_mandelbrot_ (19497), 9246 events, 25.7%, 0.000 msec
> 
> If this is acceptable to you, can someone please tell me how to do such a
> seemingly simple task in C? In C++ I'd except to add a simple std::sort
> somewhere, but in perf's C...? My current idea would be to run
> machine__for_each_thread and store the even count + thread pointer in
> another temporary buffer, which I then qsort and finally iterate over. Does
> that sound OK, or how would you approach this task?

While at it, can we similarly reorder the output of the per-thread syscall 
list? At the moment it is e.g.:

   syscall            calls    total       min       avg       max      stddev
                               (msec)    (msec)    (msec)    (msec)        (%)
   --------------- -------- --------- --------- --------- ---------     ------
   read                 166     0.332     0.001     0.002     0.031     10.22%
   write                 13     0.038     0.002     0.003     0.006     12.41%
   open                 448     1.189     0.001     0.003     0.020      1.94%
   close                185     0.270     0.001     0.001     0.022      7.78%
   stat                 507     0.823     0.001     0.002     0.009      2.34%
   fstat                215     0.211     0.001     0.001     0.001      1.00%
   lstat                317     0.469     0.001     0.001     0.003      1.42%
   poll                 176     0.534     0.001     0.003     0.169     32.22%
   lseek                  1     0.001     0.001     0.001     0.001      0.00%
   mmap                 384     1.184     0.002     0.003     0.006      1.20%
   mprotect             238     0.949     0.001     0.004     0.013      1.96%
   munmap                42     0.501     0.002     0.012     0.107     27.58%
   brk                   12     0.042     0.001     0.004     0.013     26.16%
   rt_sigaction           2     0.002     0.001     0.001     0.001     12.90%
   rt_sigprocmask         1     0.001     0.001     0.001     0.001      0.00%
   writev               165     0.387     0.002     0.002     0.005      1.57%
   access               156     0.250     0.001     0.002     0.011      4.88%
   socket                 2     0.012     0.005     0.006     0.007     12.05%
   connect                2     0.014     0.005     0.007     0.009     25.14%
   recvfrom               4     0.014     0.002     0.003     0.008     45.24%
   recvmsg               16     0.029     0.001     0.002     0.004     12.30%
   shutdown               1     0.004     0.004     0.004     0.004      0.00%
   getsockname            1     0.001     0.001     0.001     0.001      0.00%
   getpeername            1     0.002     0.002     0.002     0.002      0.00%
   getsockopt             1     0.002     0.002     0.002     0.002      0.00%
   clone                 34     7.506     0.207     0.221     0.295      1.49%
   uname                  2     0.003     0.001     0.001     0.001      4.12%
   fcntl                 32     0.032     0.001     0.001     0.001      2.53%
   getdents              16     0.057     0.001     0.004     0.007     15.32%
   readlink              11     0.020     0.001     0.002     0.005     19.02%
   getrlimit              1     0.001     0.001     0.001     0.001      0.00%
   getuid                 2     0.002     0.001     0.001     0.001     15.24%
   getgid                 1     0.001     0.001     0.001     0.001      0.00%
   geteuid                2     0.002     0.001     0.001     0.001     23.66%
   getegid                1     0.001     0.001     0.001     0.001      0.00%
   statfs                 8     0.020     0.002     0.002     0.004     10.60%
   arch_prctl             1     0.001     0.001     0.001     0.001      0.00%
   futex                489  1466.240     0.001     2.998  1447.978     98.75%
   set_tid_address        1     0.001     0.001     0.001     0.001      0.00%
   clock_getres           1     0.001     0.001     0.001     0.001      0.00%
   set_robust_list        1     0.001     0.001     0.001     0.001      0.00%

This output is not sorted by syscall name, nor by number of calls or total or 
anything... Could we maybe sort it by total msecs by default? Or maybe by 
syscall name and then offer the user a way to sort it by calls/total msecs 
instead?

Thanks
-- 
Milian Wolff | milian.wolff@kdab.com | Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 5903 bytes --]

  reply	other threads:[~2016-05-04  9:51 UTC|newest]

Thread overview: 8+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2016-05-04  9:02 Reordering the thread output in perf trace --summary Milian Wolff
2016-05-04  9:51 ` Milian Wolff [this message]
2016-05-04 21:41   ` Arnaldo Carvalho de Melo
2016-05-05 16:04     ` [DONE] " Arnaldo Carvalho de Melo
2016-05-09  8:28       ` Milian Wolff
2016-05-09 16:25         ` Arnaldo Carvalho de Melo
2016-05-09 18:03           ` Milian Wolff
2016-05-09 20:12             ` Arnaldo Carvalho de Melo

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=52227896.H02DnUL2Ue@milian-kdab2 \
    --to=milian.wolff@kdab.com \
    --cc=linux-perf-users@vger.kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).