linux-kernel - [PATCH 01/11] perf trace: Support callchains for --event too

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: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <1460558597-16895-2-git-send-email-acme@kernel.org>
Date:	Wed, 13 Apr 2016 11:43:07 -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 01/11] perf trace: Support callchains for --event too

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

We already were able to ask for callchains for a specific event:

  # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1

This would enable tracing just the "nanosleep" syscall, with callchains
at syscall exit and would ask the kernel for frame pointer callchains to
be enabled for the "sched:sched_switch" tracepoint event, its just that
we were not resolving the callchain and printing it in 'perf trace', do
it:

  # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1
     0.425 ( 0.013 ms): usleep/6718 nanosleep(rqtp: 0x7ffcc1d16e20) ...
     0.425 (         ): sched:sched_switch:usleep:6718 [120] S ==> swapper/2:0 [120])
                                       __schedule+0xfe200402 ([kernel.kallsyms])
                                       schedule+0xfe200035 ([kernel.kallsyms])
                                       do_nanosleep+0xfe20006f ([kernel.kallsyms])
                                       hrtimer_nanosleep+0xfe2000dc ([kernel.kallsyms])
                                       sys_nanosleep+0xfe20007a ([kernel.kallsyms])
                                       do_syscall_64+0xfe200062 ([kernel.kallsyms])
                                       return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                                       __nanosleep+0xffff008b8cbe2010 (/usr/lib64/libc-2.22.so)
     0.486 ( 0.073 ms): usleep/6718  ... [continued]: nanosleep()) = 0
                                       __nanosleep+0x10 (/usr/lib64/libc-2.22.so)
                                       usleep+0x34 (/usr/lib64/libc-2.22.so)
                                       main+0x1eb (/usr/bin/usleep)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       _start+0x29 (/usr/bin/usleep)
  #

Pretty compact, huh? DWARF callchains for raw_syscalls:sys_exit + frame
pointer callchains for a tracepoint, if your hardware supports LBR, go
wild with /call-graph=lbr/, guess the next step is to lift this from
'perf script':

  -F, --fields <str>    comma separated output fields prepend with 'type:'. Valid types: hw,sw,trace,raw.
                        Fields: comm,tid,pid,time,cpu,event,trace,ip,sym,dso,addr,symoff,period,iregs,brstack,brstacksym,flags

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-2e7yiv5hqdm8jywlmfivvx2v@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>
---
 tools/perf/builtin-trace.c | 41 ++++++++++++++++++++++++++---------------
 1 file changed, 26 insertions(+), 15 deletions(-)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 2ec53edcf649..a6e05e1bb350 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2114,6 +2114,28 @@ out_put:
 	return err;
 }
 
+static int trace__fprintf_callchain(struct trace *trace, struct perf_evsel *evsel,
+				    struct perf_sample *sample)
+{
+	struct addr_location al;
+	/* TODO: user-configurable print_opts */
+	const unsigned int print_opts = PRINT_IP_OPT_SYM |
+				        PRINT_IP_OPT_DSO |
+				        PRINT_IP_OPT_UNKNOWN_AS_ADDR;
+
+	if (sample->callchain == NULL)
+		return 0;
+
+	if (machine__resolve(trace->host, &al, sample) < 0) {
+		pr_err("Problem processing %s callchain, skipping...\n",
+			perf_evsel__name(evsel));
+		return 0;
+	}
+
+	return perf_evsel__fprintf_callchain(evsel, sample, &al, 38, print_opts,
+					     scripting_max_stack, trace->output);
+}
+
 static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
 			   union perf_event *event __maybe_unused,
 			   struct perf_sample *sample)
@@ -2193,21 +2215,7 @@ signed_print:
 
 	fputc('\n', trace->output);
 
-	if (sample->callchain) {
-		struct addr_location al;
-		/* TODO: user-configurable print_opts */
-		const unsigned int print_opts = PRINT_IP_OPT_SYM |
-					        PRINT_IP_OPT_DSO |
-					        PRINT_IP_OPT_UNKNOWN_AS_ADDR;
-
-		if (machine__resolve(trace->host, &al, sample) < 0) {
-			pr_err("problem processing %d event, skipping it.\n",
-			       event->header.type);
-			goto out_put;
-		}
-		perf_evsel__fprintf_callchain(evsel, sample, &al, 38, print_opts,
-					      scripting_max_stack, trace->output);
-	}
+	trace__fprintf_callchain(trace, evsel, sample);
 out:
 	ttrace->entry_pending = false;
 	err = 0;
@@ -2355,6 +2363,9 @@ static int trace__event_handler(struct trace *trace, struct perf_evsel *evsel,
 	}
 
 	fprintf(trace->output, ")\n");
+
+	trace__fprintf_callchain(trace, evsel, sample);
+
 	return 0;
 }
 
-- 
2.5.5