aboutsummaryrefslogtreecommitdiffstats
path: root/tools
diff options
context:
space:
mode:
authorPekka Enberg <penberg@kernel.org>2013-11-12 09:42:14 -0500
committerArnaldo Carvalho de Melo <acme@redhat.com>2013-11-12 11:00:38 -0500
commit99ff7150547382ee612c40d8d6a0670ddec7c9fc (patch)
tree66ccf41ee62c5740d8d6adeca2d40c0d5f19b772 /tools
parent7f7a4138c66e857cc5bbf6e248a47379765349b5 (diff)
perf trace: Simplify '--summary' output
The output of 'perf trace --summary' tries to be too cute with formatting and makes it very hard to read. Simplify it in the spirit of "strace -c": [penberg@localhost libtrading]$ perf trace -a --duration 10000 --summary -- sleep 1 ^C Summary of events: dbus-daemon (555), 10 events, 0.0%, 0.000 msec msec/call syscall calls min avg max stddev --------------- -------- -------- -------- -------- ------ sendmsg 2 0.002 0.005 0.008 55.00 recvmsg 2 0.002 0.003 0.005 44.00 epoll_wait 1 0.000 0.000 0.000 0.00 NetworkManager (667), 56 events, 0.0%, 0.000 msec msec/call syscall calls min avg max stddev --------------- -------- -------- -------- -------- ------ poll 2 0.000 0.002 0.003 100.00 sendmsg 10 0.004 0.007 0.016 15.41 recvmsg 16 0.002 0.003 0.005 8.24 zfs-fuse (669), 4 events, 0.0%, 0.000 msec msec/call syscall calls min avg max stddev --------------- -------- -------- -------- -------- ------ futex 2 0.000 0.001 0.002 100.00 Signed-off-by: Pekka Enberg <penberg@kernel.org> Cc: David Ahern <dsahern@gmail.com> Cc: Ingo Molnar <mingo@redhat.com> Link: http://lkml.kernel.org/r/1384267334-18953-1-git-send-email-penberg@kernel.org Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Diffstat (limited to 'tools')
-rw-r--r--tools/perf/builtin-trace.c25
1 files changed, 12 insertions, 13 deletions
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 8990fbeb8b41..0964c0cdc982 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2090,12 +2090,7 @@ static size_t trace__fprintf_threads_header(FILE *fp)
2090{ 2090{
2091 size_t printed; 2091 size_t printed;
2092 2092
2093 printed = fprintf(fp, "\n _____________________________________________________________________________\n"); 2093 printed = fprintf(fp, "\n Summary of events:\n\n");
2094 printed += fprintf(fp, " __) Summary of events (__\n\n");
2095 printed += fprintf(fp, " [ task - pid ] [ events ] [ ratio ] [ runtime ]\n");
2096 printed += fprintf(fp, " syscall count min avg max stddev\n");
2097 printed += fprintf(fp, " msec msec msec %%\n");
2098 printed += fprintf(fp, " _____________________________________________________________________________\n\n");
2099 2094
2100 return printed; 2095 return printed;
2101} 2096}
@@ -2113,6 +2108,10 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
2113 2108
2114 printed += fprintf(fp, "\n"); 2109 printed += fprintf(fp, "\n");
2115 2110
2111 printed += fprintf(fp, " msec/call\n");
2112 printed += fprintf(fp, " syscall calls min avg max stddev\n");
2113 printed += fprintf(fp, " --------------- -------- -------- -------- -------- ------\n");
2114
2116 /* each int_node is a syscall */ 2115 /* each int_node is a syscall */
2117 while (inode) { 2116 while (inode) {
2118 stats = inode->priv; 2117 stats = inode->priv;
@@ -2127,10 +2126,10 @@ static size_t thread__dump_stats(struct thread_trace *ttrace,
2127 avg /= NSEC_PER_MSEC; 2126 avg /= NSEC_PER_MSEC;
2128 2127
2129 sc = &trace->syscalls.table[inode->i]; 2128 sc = &trace->syscalls.table[inode->i];
2130 printed += fprintf(fp, "%24s %14s : ", "", sc->name); 2129 printed += fprintf(fp, " %-15s", sc->name);
2131 printed += fprintf(fp, "%5" PRIu64 " %8.3f %8.3f", 2130 printed += fprintf(fp, " %8" PRIu64 " %8.3f %8.3f",
2132 n, min, avg); 2131 n, min, avg);
2133 printed += fprintf(fp, " %8.3f %6.2f\n", max, pct); 2132 printed += fprintf(fp, " %8.3f %6.2f\n", max, pct);
2134 } 2133 }
2135 2134
2136 inode = intlist__next(inode); 2135 inode = intlist__next(inode);
@@ -2171,10 +2170,10 @@ static int trace__fprintf_one_thread(struct thread *thread, void *priv)
2171 else if (ratio > 5.0) 2170 else if (ratio > 5.0)
2172 color = PERF_COLOR_YELLOW; 2171 color = PERF_COLOR_YELLOW;
2173 2172
2174 printed += color_fprintf(fp, color, "%20s", thread__comm_str(thread)); 2173 printed += color_fprintf(fp, color, " %s (%d), ", thread__comm_str(thread), thread->tid);
2175 printed += fprintf(fp, " - %-5d :%11lu [", thread->tid, ttrace->nr_events); 2174 printed += fprintf(fp, "%lu events, ", ttrace->nr_events);
2176 printed += color_fprintf(fp, color, "%5.1f%%", ratio); 2175 printed += color_fprintf(fp, color, "%.1f%%", ratio);
2177 printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms); 2176 printed += fprintf(fp, ", %.3f msec\n", ttrace->runtime_ms);
2178 printed += thread__dump_stats(ttrace, trace, fp); 2177 printed += thread__dump_stats(ttrace, trace, fp);
2179 2178
2180 data->printed += printed; 2179 data->printed += printed;