From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757535AbcDMOnd (ORCPT ); Wed, 13 Apr 2016 10:43:33 -0400 Received: from bombadil.infradead.org ([198.137.202.9]:52929 "EHLO bombadil.infradead.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1757425AbcDMOn1 (ORCPT ); Wed, 13 Apr 2016 10:43:27 -0400 From: Arnaldo Carvalho de Melo To: Ingo Molnar Cc: linux-kernel@vger.kernel.org, Arnaldo Carvalho de Melo , Adrian Hunter , David Ahern , Jiri Olsa , Milian Wolff , Namhyung Kim , Wang Nan Subject: [PATCH 01/11] perf trace: Support callchains for --event too Date: Wed, 13 Apr 2016 11:43:07 -0300 Message-Id: <1460558597-16895-2-git-send-email-acme@kernel.org> X-Mailer: git-send-email 2.5.5 In-Reply-To: <1460558597-16895-1-git-send-email-acme@kernel.org> References: <1460558597-16895-1-git-send-email-acme@kernel.org> X-SRS-Rewrite: SMTP reverse-path rewritten from by bombadil.infradead.org. See http://www.infradead.org/rpr.html Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Arnaldo Carvalho de Melo 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 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 Cc: David Ahern Cc: Jiri Olsa Cc: Milian Wolff Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-2e7yiv5hqdm8jywlmfivvx2v@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- 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