perf trace: Sort syscalls stats by msecs in --summary
authorArnaldo Carvalho de Melo <acme@redhat.com>
Wed, 4 May 2016 19:06:26 +0000 (16:06 -0300)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Fri, 6 May 2016 00:03:56 +0000 (21:03 -0300)
  # trace -a -s sleep 1
  <SNIP>
   Xorg (1965), 788 events, 19.0%, 0.000 msec

     syscall            calls    total       min       avg       max      stddev
                                 (msec)    (msec)    (msec)    (msec)        (%)
     --------------- -------- --------- --------- --------- ---------     ------
     select                89   731.038     0.000     8.214   175.218     36.71%
     ioctl                 22     0.661     0.010     0.030     0.072     10.43%
     writev                42     0.253     0.002     0.006     0.011      5.94%
     recvmsg               60     0.185     0.001     0.003     0.009      5.90%
     setitimer             60     0.127     0.001     0.002     0.006      6.14%
     read                  52     0.102     0.001     0.002     0.005      8.55%
     rt_sigprocmask        45     0.092     0.001     0.002     0.023     23.65%
     poll                  12     0.021     0.001     0.002     0.003      7.21%
     epoll_wait            12     0.019     0.001     0.002     0.002      2.71%

   firefox (10871), 1080 events, 26.1%, 0.000 msec

     syscall            calls    total       min       avg       max      stddev
                                 (msec)    (msec)    (msec)    (msec)        (%)
     --------------- -------- --------- --------- --------- ---------     ------
     poll                 240   979.562     0.000     4.082    17.132     11.33%
     recvmsg              240     0.532     0.001     0.002     0.007      3.69%
     read                  60     0.303     0.003     0.005     0.029      8.50%

Suggested-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-52kdkuyxihq0kvc0n2aalhay@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/builtin-trace.c

index aac0074..c61e612 100644 (file)
@@ -2785,15 +2785,29 @@ static size_t trace__fprintf_threads_header(FILE *fp)
        return printed;
 }
 
+DEFINE_RESORT_RB(syscall_stats, a->msecs > b->msecs,
+       struct stats    *stats;
+       double          msecs;
+       int             syscall;
+)
+{
+       struct int_node *source = rb_entry(nd, struct int_node, rb_node);
+       struct stats *stats = source->priv;
+
+       entry->syscall = source->i;
+       entry->stats   = stats;
+       entry->msecs   = stats ? (u64)stats->n * (avg_stats(stats) / NSEC_PER_MSEC) : 0;
+}
+
 static size_t thread__dump_stats(struct thread_trace *ttrace,
                                 struct trace *trace, FILE *fp)
 {
-       struct stats *stats;
        size_t printed = 0;
        struct syscall *sc;
-       struct int_node *inode = intlist__first(ttrace->syscall_stats);
+       struct rb_node *nd;
+       DECLARE_RESORT_RB_INTLIST(syscall_stats, ttrace->syscall_stats);
 
-       if (inode == NULL)
+       if (syscall_stats == NULL)
                return 0;
 
        printed += fprintf(fp, "\n");
@@ -2802,9 +2816,8 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
        printed += fprintf(fp, "                               (msec)    (msec)    (msec)    (msec)        (%%)\n");
        printed += fprintf(fp, "   --------------- -------- --------- --------- --------- ---------     ------\n");
 
-       /* each int_node is a syscall */
-       while (inode) {
-               stats = inode->priv;
+       resort_rb__for_each(nd, syscall_stats) {
+               struct stats *stats = syscall_stats_entry->stats;
                if (stats) {
                        double min = (double)(stats->min) / NSEC_PER_MSEC;
                        double max = (double)(stats->max) / NSEC_PER_MSEC;
@@ -2815,16 +2828,15 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
                        pct = avg ? 100.0 * stddev_stats(stats)/avg : 0.0;
                        avg /= NSEC_PER_MSEC;
 
-                       sc = &trace->syscalls.table[inode->i];
+                       sc = &trace->syscalls.table[syscall_stats_entry->syscall];
                        printed += fprintf(fp, "   %-15s", sc->name);
                        printed += fprintf(fp, " %8" PRIu64 " %9.3f %9.3f %9.3f",
-                                          n, avg * n, min, avg);
+                                          n, syscall_stats_entry->msecs, min, avg);
                        printed += fprintf(fp, " %9.3f %9.2f%%\n", max, pct);
                }
-
-               inode = intlist__next(inode);
        }
 
+       resort_rb__delete(syscall_stats);
        printed += fprintf(fp, "\n\n");
 
        return printed;