perf trace: Fix syscall enter formatting bug
authorArnaldo Carvalho de Melo <acme@redhat.com>
Wed, 25 Mar 2015 21:01:15 +0000 (18:01 -0300)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Thu, 26 Mar 2015 13:52:29 +0000 (10:52 -0300)
 commit e596663ebb28a068f5cca57f83285b7b293a2c83
 Author: Arnaldo Carvalho de Melo <acme@redhat.com>
 Date:   Fri Feb 13 13:22:21 2015 -0300

    perf trace: Handle multiple threads better wrt syscalls being intermixed

Introduced a bug where it considered the number of bytes output directly
to the output file when formatting the syscall entry buffer that is
stored to be finally printed at syscall exit, ending up leaving garbage
at the start of syscalls that appeared while another syscall was being
processed, in another thread. Fix it.

Example of garbage in the output before this patch:

 4280.102 (  0.000 ms): lsmd/763  ... [continued]: select()) = 0 Timeout
 4280.107 (275.250 ms): tuned/852 select(tvp: 0x7f41f7ffde50        ) ...
 4280.109 (  0.002 ms): lsmd/763 Xl��                                ) = -10
 4639.197 (  0.000 ms): systemd-journa/542  ... [continued]: epoll_wait()) = 1
 4639.202 (359.088 ms): lsmd/763 select(n: 6, inp: 0x7ffff21daad0, tvp: 0x7ffff21daac0) ...
 4639.207 (  0.005 ms): systemd-journa/542 Hn��                      ) = 106
 4639.221 (  0.002 ms): systemd-journa/542 uname(name: 0x7ffdbaed8e00) = 0
 4639.271 (  0.008 ms): systemd-journa/542 ftruncate(fd: 11</run/log/journal/60cd52417cf440a4a80107518bbd3c20/system.journal>, length: 50331648) = 0

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-9ckfe8mvsedgkg6y80gz1ul8@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/builtin-trace.c

index 001c6ae9a1b1094b909cdecc7cb69611b0653222..bcc98ce3e5b8fc2bdb72e1550e00b15418a2903e 100644 (file)
@@ -1735,7 +1735,7 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
        }
 
        if (!trace->summary_only)
-               printed += trace__printf_interrupted_entry(trace, sample);
+               trace__printf_interrupted_entry(trace, sample);
 
        ttrace->entry_time = sample->time;
        msg = ttrace->entry_str;