linux-kernel - [PATCH 09/10] perf trace: Don't set the base timestamp using events without PERF_SAMPLE

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite for Android: free password hash cracker in your pocket

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-Id: <1459547826-20100-10-git-send-email-acme@kernel.org>
Date:	Fri,  1 Apr 2016 18:57:05 -0300
From:	Arnaldo Carvalho de Melo <acme@...nel.org>
To:	Ingo Molnar <mingo@...nel.org>
Cc:	linux-kernel@...r.kernel.org,
	Arnaldo Carvalho de Melo <acme@...hat.com>,
	Adrian Hunter <adrian.hunter@...el.com>,
	David Ahern <dsahern@...il.com>, Jiri Olsa <jolsa@...nel.org>,
	Milian Wolff <milian.wolff@...b.com>,
	Namhyung Kim <namhyung@...nel.org>,
	Wang Nan <wangnan0@...wei.com>
Subject: [PATCH 09/10] perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME

From: Arnaldo Carvalho de Melo <acme@...hat.com>

This was causing bogus values to be shown at the timestamp column:

Before:

  # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
  94631143.385 ( 0.001 ms): brk(                                     ) = 0x555555757000
  94631143.398 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7ffff7ff6000
  94631143.406 ( 0.004 ms): access(filename: 0xf7df9e10, mode: R     ) = -1 ENOENT No such file or directory
  94631143.412 ( 0.004 ms): open(filename: 0xf7df8761, flags: CLOEXEC) = 3
  94631143.415 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fffffffd6b0     ) = 0
  94631143.419 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7ffff7fdb000
  94631143.420 ( 0.001 ms): close(fd: 3                              ) = 0
  94631143.432 ( 0.004 ms): open(filename: 0xf7ff6640, flags: CLOEXEC) = 3
  <SNIP>

After:

  # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
  0.022 ( 0.001 ms): brk(                                     ) = 0x55d7668a6000
  0.037 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7f8fbeb97000
  0.123 ( 0.083 ms): access(filename: 0xbe995e10, mode: R     ) = -1 ENOENT No such file or directory
  0.130 ( 0.004 ms): open(filename: 0xbe994761, flags: CLOEXEC) = 3
  0.133 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fff6487a890     ) = 0
  0.138 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8fbeb7c000
  0.140 ( 0.001 ms): close(fd: 3                              ) = 0
  0.151 ( 0.004 ms): open(filename: 0xbeb97640, flags: CLOEXEC) = 3
  <SNIP>

Cc: Adrian Hunter <adrian.hunter@...el.com>
Cc: David Ahern <dsahern@...il.com>
Cc: Jiri Olsa <jolsa@...nel.org>
Cc: Milian Wolff <milian.wolff@...b.com>
Cc: Namhyung Kim <namhyung@...nel.org>
Cc: Wang Nan <wangnan0@...wei.com>
Link: http://lkml.kernel.org/n/tip-p7m8llv81iv55ekxexdp5n57@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>
---
 tools/perf/builtin-trace.c | 13 +++++++++++--
 1 file changed, 11 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 99daeed55a9b..d309f4535a45 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2401,10 +2401,19 @@ static bool skip_sample(struct trace *trace, struct perf_sample *sample)
 }
 
 static void trace__set_base_time(struct trace *trace,
-				 struct perf_evsel *evsel __maybe_unused,
+				 struct perf_evsel *evsel,
 				 struct perf_sample *sample)
 {
-	if (trace->base_time == 0 && !trace->full_time)
+	/*
+	 * BPF events were not setting PERF_SAMPLE_TIME, so be more robust
+	 * and don't use sample->time unconditionally, we may end up having
+	 * some other event in the future without PERF_SAMPLE_TIME for good
+	 * reason, i.e. we may not be interested in its timestamps, just in
+	 * it taking place, picking some piece of information when it
+	 * appears in our event stream (vfs_getname comes to mind).
+	 */
+	if (trace->base_time == 0 && !trace->full_time &&
+	    (evsel->attr.sample_type & PERF_SAMPLE_TIME))
 		trace->base_time = sample->time;
 }
 
-- 
2.5.5