From cbd5c1787bab4643e5959522275b46de94eba5ac Mon Sep 17 00:00:00 2001 From: Andrei Vagin Date: Tue, 7 Nov 2017 16:22:46 -0800 Subject: perf trace: Fix an exit code of trace__symbols_init Currently if trace_event__register_resolver() fails, we return -errno, but we can't be sure that errno isn't zero in this case. Signed-off-by: Andrei Vagin Reviewed-by: Jiri Olsa Cc: Alexander Shishkin Cc: Namhyung Kim Cc: Peter Zijlstra Cc: Vasily Averin Link: http://lkml.kernel.org/r/20171108002246.8924-2-avagin@openvz.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index f2757d38c7d7..84debdbad327 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -1152,12 +1152,14 @@ static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist) if (trace->host == NULL) return -ENOMEM; - if (trace_event__register_resolver(trace->host, trace__machine__resolve_kernel_addr) < 0) - return -errno; + err = trace_event__register_resolver(trace->host, trace__machine__resolve_kernel_addr); + if (err < 0) + goto out; err = __machine__synthesize_threads(trace->host, &trace->tool, &trace->opts.target, evlist->threads, trace__tool_process, false, trace->opts.proc_map_timeout, 1); +out: if (err) symbol__exit(); -- cgit v1.2.2 From f74b9d3a1ac2b9c3ae1475f474ca0e6644746fbf Mon Sep 17 00:00:00 2001 From: Wang Nan Date: Sun, 3 Dec 2017 02:00:37 +0000 Subject: perf evlist: Remove 'overwrite' parameter from perf_evlist__mmap Now all perf_evlist__mmap's users doesn't set 'overwrite'. Remove it from arguments list. Signed-off-by: Wang Nan Acked-by: Namhyung Kim Cc: Jiri Olsa Cc: Kan Liang Link: http://lkml.kernel.org/r/20171203020044.81680-2-wangnan0@huawei.com Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 84debdbad327..7c57898095ea 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -2437,7 +2437,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv) if (err < 0) goto out_error_apply_filters; - err = perf_evlist__mmap(evlist, trace->opts.mmap_pages, false); + err = perf_evlist__mmap(evlist, trace->opts.mmap_pages); if (err < 0) goto out_error_mmap; -- cgit v1.2.2 From 2d1073def3cb69aa44f99be7ef42da7cc561be1f Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Tue, 9 Jan 2018 12:03:47 -0300 Subject: perf trace: Beautify 'gettid' syscall result Before: # trace -a -e gettid sleep 0.01 4.863 ( 0.005 ms): Chrome_ChildIO/26241 gettid() = 26241 4.931 ( 0.004 ms): Chrome_IOThrea/26154 gettid() = 26154 4.942 ( 0.001 ms): Chrome_IOThrea/26154 gettid() = 26154 4.946 ( 0.001 ms): Chrome_IOThrea/26154 gettid() = 26154 4.970 ( 0.002 ms): Chrome_IOThrea/26154 gettid() = 26154 # After: # trace -a -e gettid sleep 0.01 0.000 ( 0.009 ms): Chrome_IOThrea/26154 gettid() = 26154 (Chrome_IOThread) 3.416 ( 0.002 ms): Chrome_ChildIO/26241 gettid() = 26241 (Chrome_ChildIOT) 3.424 ( 0.001 ms): Chrome_ChildIO/26241 gettid() = 26241 (Chrome_ChildIOT) 3.343 ( 0.002 ms): chrome/26116 gettid() = 26116 (chrome) 3.386 ( 0.002 ms): Chrome_IOThrea/26154 gettid() = 26154 (Chrome_IOThread) 4.003 ( 0.003 ms): Chrome_ChildIO/26241 gettid() = 26241 (Chrome_ChildIOT) 4.031 ( 0.002 ms): Chrome_IOThrea/26154 gettid() = 26154 (Chrome_IOThread) # Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-kyg4gz2yy0vkrrh2vtq29u71@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 1 + 1 file changed, 1 insertion(+) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 7c57898095ea..71e64bdca86f 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -622,6 +622,7 @@ static struct syscall_fmt { .arg = { [2] = { .scnprintf = SCA_GETRANDOM_FLAGS, /* flags */ }, }, }, { .name = "getrlimit", .arg = { [0] = STRARRAY(resource, rlimit_resources), }, }, + { .name = "gettid", .errpid = true, }, { .name = "ioctl", .arg = { #if defined(__i386__) || defined(__x86_64__) -- cgit v1.2.2 From 236d812c55c2f38665663f0af61606b1cecea825 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Fri, 12 Jan 2018 13:14:52 -0300 Subject: perf trace: No need to set PERF_SAMPLE_IDENTIFIER explicitely Since 75562573bab3 ("perf tools: Add support for PERF_SAMPLE_IDENTIFIER") we don't need explicitely set PERF_SAMPLE_IDENTIFIER, as perf_evlist__config() will do this for us, i.e. when there are more than one evsel in an evlist, it will check if some evsel has a sample_type different than the one on the first evsel in the list, setting PERF_SAMPLE_IDENTIFIER in that case. So, to simplify 'perf trace' codebase, ditch that check. Cc: Adrian Hunter Cc: David Ahern Cc: Hendrick Brueckner Cc: Jiri Olsa Cc: Namhyung Kim Cc: Thomas Richter Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-12xq6orhwttee2tdtu96ucrp@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 23 ----------------------- 1 file changed, 23 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 71e64bdca86f..e84816d02117 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -2348,40 +2348,17 @@ static int trace__run(struct trace *trace, int argc, const char **argv) perf_evlist__config(evlist, &trace->opts, NULL); if (callchain_param.enabled) { - bool use_identifier = false; - if (trace->syscalls.events.sys_exit) { perf_evsel__config_callchain(trace->syscalls.events.sys_exit, &trace->opts, &callchain_param); - use_identifier = true; } if (pgfault_maj) { perf_evsel__config_callchain(pgfault_maj, &trace->opts, &callchain_param); - use_identifier = true; } if (pgfault_min) { perf_evsel__config_callchain(pgfault_min, &trace->opts, &callchain_param); - use_identifier = true; - } - - if (use_identifier) { - /* - * Now we have evsels with different sample_ids, use - * PERF_SAMPLE_IDENTIFIER to map from sample to evsel - * from a fixed position in each ring buffer record. - * - * As of this the changeset introducing this comment, this - * isn't strictly needed, as the fields that can come before - * PERF_SAMPLE_ID are all used, but we'll probably disable - * some of those for things like copying the payload of - * pointer syscall arguments, and for vfs_getname we don't - * need PERF_SAMPLE_ADDR and PERF_SAMPLE_IP, so do this - * here as a warning we need to use PERF_SAMPLE_IDENTIFIER. - */ - perf_evlist__set_sample_bit(evlist, IDENTIFIER); - perf_evlist__reset_sample_bit(evlist, ID); } } -- cgit v1.2.2 From 08e26396c6f29642fecfb7ca083459264a033a89 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Fri, 12 Jan 2018 13:29:05 -0300 Subject: perf trace: Fix setting of --call-graph/--max-stack for non-syscall events The raw_syscalls:sys_{enter,exit} were first supported in 'perf trace', together with minor and major page faults, then we supported --call-graph, then --max-stack, but when the other tracepoints got supported, and bpf, etc, I forgot to make those global call-graph settings apply to them. Fix it by realizing that the global --max-stack and --call-graph settings are done via: OPT_CALLBACK(0, "call-graph", &trace.opts, "record_mode[,record_size]", record_callchain_help, &record_parse_callchain_opt), And then, when we go to parse the events in -e via: OPT_CALLBACK('e', "event", &trace, "event", "event/syscall selector. use 'perf list' to list available events", trace__parse_events_option), And trace__parse_sevents_option() calls: struct option o = OPT_CALLBACK('e', "event", &trace->evlist, "event", "event selector. use 'perf list' to list available events", parse_events_option); err = parse_events_option(&o, lists[0], 0); parse_events_option() will override the global --call-graph and --max-stack if the "call-graph" and/or "max-stack" terms are in the event definition, such as in the probe_libc:inet_pton event in one of the examples below (-e probe_libc:inet_pton/max-stack=2). Before: # perf trace --mmap 1024 --call-graph dwarf -e sendto,probe_libc:inet_pton ping -6 -c 1 ::1 1.525 ( ): probe_libc:inet_pton:(7f77f3ac9350)) PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.071 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.071/0.071/0.071/0.000 ms 1.677 ( 0.081 ms): ping/31296 sendto(fd: 3, buff: 0x55681b652720, len: 64, addr: 0x55681b650640, addr_len: 28) = 64 __libc_sendto (/usr/lib64/libc-2.26.so) [0xffffaa97e4bc9cef] (/usr/bin/ping) [0xffffaa97e4bc656d] (/usr/bin/ping) [0xffffaa97e4bc7d0a] (/usr/bin/ping) [0xffffaa97e4bca447] (/usr/bin/ping) [0xffffaa97e4bc2f91] (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) [0xffffaa97e4bc3379] (/usr/bin/ping) # After: # perf trace --mmap 1024 --call-graph dwarf -e sendto,probe_libc:inet_pton ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.089 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.089/0.089/0.089/0.000 ms 1.955 ( ): probe_libc:inet_pton:(7f383a311350)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) __GI_getaddrinfo (inlined) [0xffffaa5d91444f3f] (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) [0xffffaa5d91445379] (/usr/bin/ping) 2.140 ( 0.101 ms): ping/32047 sendto(fd: 3, buff: 0x55a26edd0720, len: 64, addr: 0x55a26edce640, addr_len: 28) = 64 __libc_sendto (/usr/lib64/libc-2.26.so) [0xffffaa5d9144bcef] (/usr/bin/ping) [0xffffaa5d9144856d] (/usr/bin/ping) [0xffffaa5d91449d0a] (/usr/bin/ping) [0xffffaa5d9144c447] (/usr/bin/ping) [0xffffaa5d91444f91] (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) [0xffffaa5d91445379] (/usr/bin/ping) # Same thing for --max-stack, the global one: # perf trace --max-stack 3 -e sendto,probe_libc:inet_pton ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.097 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.097/0.097/0.097/0.000 ms 1.577 ( ): probe_libc:inet_pton:(7f32f3957350)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) __GI_getaddrinfo (inlined) 1.738 ( 0.108 ms): ping/32103 sendto(fd: 3, buff: 0x55c3132d7720, len: 64, addr: 0x55c3132d5640, addr_len: 28) = 64 __libc_sendto (/usr/lib64/libc-2.26.so) [0xffffaa3cecf44cef] (/usr/bin/ping) [0xffffaa3cecf4156d] (/usr/bin/ping) # And then setting up a global setting (dwarf, max-stack=4), that will affect the raw_syscall:sys_enter for the 'sendto' syscall and that will be overriden in the probe_libc:inet_pton call to just one entry. # perf trace --max-stack=4 --call-graph dwarf -e sendto -e probe_libc:inet_pton/max-stack=1/ ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.090 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.090/0.090/0.090/0.000 ms 2.140 ( ): probe_libc:inet_pton:(7f9fe9337350)) __GI___inet_pton (/usr/lib64/libc-2.26.so) 2.283 ( 0.103 ms): ping/31804 sendto(fd: 3, buff: 0x55c7f3e19720, len: 64, addr: 0x55c7f3e17640, addr_len: 28) = 64 __libc_sendto (/usr/lib64/libc-2.26.so) [0xffffaa380c402cef] (/usr/bin/ping) [0xffffaa380c3ff56d] (/usr/bin/ping) [0xffffaa380c400d0a] (/usr/bin/ping) # Install iputils-debuginfo to get those /usr/bin/ping addresses resolved, those routines are not on its .dymsym nor .symtab :-) Cc: Adrian Hunter Cc: David Ahern Cc: Hendrick Brueckner Cc: Jiri Olsa Cc: Namhyung Kim Cc: Thomas Richter Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-qgl2gse8elhh9zztw4ajopg3@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 20 +++++--------------- 1 file changed, 5 insertions(+), 15 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index e84816d02117..0362974854e9 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -2222,6 +2222,9 @@ static int trace__add_syscall_newtp(struct trace *trace) if (perf_evsel__init_sc_tp_uint_field(sys_exit, ret)) goto out_delete_sys_exit; + perf_evsel__config_callchain(sys_enter, &trace->opts, &callchain_param); + perf_evsel__config_callchain(sys_exit, &trace->opts, &callchain_param); + perf_evlist__add(evlist, sys_enter); perf_evlist__add(evlist, sys_exit); @@ -2318,6 +2321,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv) pgfault_maj = perf_evsel__new_pgfault(PERF_COUNT_SW_PAGE_FAULTS_MAJ); if (pgfault_maj == NULL) goto out_error_mem; + perf_evsel__config_callchain(pgfault_maj, &trace->opts, &callchain_param); perf_evlist__add(evlist, pgfault_maj); } @@ -2325,6 +2329,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv) pgfault_min = perf_evsel__new_pgfault(PERF_COUNT_SW_PAGE_FAULTS_MIN); if (pgfault_min == NULL) goto out_error_mem; + perf_evsel__config_callchain(pgfault_min, &trace->opts, &callchain_param); perf_evlist__add(evlist, pgfault_min); } @@ -2347,21 +2352,6 @@ static int trace__run(struct trace *trace, int argc, const char **argv) perf_evlist__config(evlist, &trace->opts, NULL); - if (callchain_param.enabled) { - if (trace->syscalls.events.sys_exit) { - perf_evsel__config_callchain(trace->syscalls.events.sys_exit, - &trace->opts, &callchain_param); - } - - if (pgfault_maj) { - perf_evsel__config_callchain(pgfault_maj, &trace->opts, &callchain_param); - } - - if (pgfault_min) { - perf_evsel__config_callchain(pgfault_min, &trace->opts, &callchain_param); - } - } - signal(SIGCHLD, sig_handler); signal(SIGINT, sig_handler); -- cgit v1.2.2 From 75d501171462d8624fd14a2baa474476d6745e95 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 15 Jan 2018 10:39:55 -0300 Subject: perf trace: Setup DWARF callchains for non-syscall events when --max-stack is used If we use: perf trace --max-stack=4 then the syscall events will use DWARF callchains, when available (libunwind enabled in the build) and the printing will stop at 4 levels. When we introduced support for tracepoint events this ended up not applying for them, fix it. Before: # perf trace --call-graph=dwarf --no-syscalls -e probe_libc:inet_pton ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.058 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.058/0.058/0.058/0.000 ms 0.000 probe_libc:inet_pton:(7fc6c2a16350)) # After: # perf trace --call-graph=dwarf --no-syscalls -e probe_libc:inet_pton ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.087 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.087/0.087/0.087/0.000 ms 0.000 probe_libc:inet_pton:(7fbf9a041350)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) __GI_getaddrinfo (inlined) [0xffffaa947cb67f3f] (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) [0xffffaa947cb68379] (/usr/bin/ping) # Reported-by: Thomas Richter Cc: Adrian Hunter Cc: David Ahern Cc: Hendrick Brueckner Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-afsu9eegd43ppihiuafhh9qv@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 0362974854e9..ee85c29dbf70 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -2350,7 +2350,7 @@ static int trace__run(struct trace *trace, int argc, const char **argv) goto out_delete_evlist; } - perf_evlist__config(evlist, &trace->opts, NULL); + perf_evlist__config(evlist, &trace->opts, &callchain_param); signal(SIGCHLD, sig_handler); signal(SIGINT, sig_handler); @@ -3065,8 +3065,9 @@ int cmd_trace(int argc, const char **argv) } #ifdef HAVE_DWARF_UNWIND_SUPPORT - if ((trace.min_stack || max_stack_user_set) && !callchain_param.enabled && trace.trace_syscalls) + if ((trace.min_stack || max_stack_user_set) && !callchain_param.enabled) { record_opts__parse_callchain(&trace.opts, &callchain_param, "dwarf", false); + } #endif if (callchain_param.enabled) { -- cgit v1.2.2 From bd3dda9ab0fbdb8a91a2e869d93a0c9692b8444f Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 15 Jan 2018 11:33:53 -0300 Subject: perf trace: Allow overriding global --max-stack per event The per-event max-stack setting wasn't overriding the global --max-stack setting: # perf trace --no-syscalls --max-stack 4 -e probe_libc:inet_pton/call-graph=dwarf,max-stack=2/ ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.072 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.072/0.072/0.072/0.000 ms 0.000 probe_libc:inet_pton:(7feb7a998350)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) __GI_getaddrinfo (inlined) [0xffffaa39b6108f3f] (/usr/bin/ping) # Fix it: # perf trace --no-syscalls --max-stack 4 -e probe_libc:inet_pton/call-graph=dwarf,max-stack=2/ ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.073 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.073/0.073/0.073/0.000 ms 0.000 probe_libc:inet_pton:(7f1083221350)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) # Cc: Adrian Hunter Cc: David Ahern Cc: Hendrick Brueckner Cc: Jiri Olsa Cc: Namhyung Kim Cc: Thomas Richter Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-ic3g837xg8ob3kcpkspxwz0g@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index ee85c29dbf70..531d43bf57e1 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -1644,7 +1644,7 @@ static int trace__resolve_callchain(struct trace *trace, struct perf_evsel *evse struct addr_location al; if (machine__resolve(trace->host, &al, sample) < 0 || - thread__resolve_callchain(al.thread, cursor, evsel, sample, NULL, NULL, trace->max_stack)) + thread__resolve_callchain(al.thread, cursor, evsel, sample, NULL, NULL, evsel->attr.sample_max_stack)) return -1; return 0; @@ -2423,6 +2423,18 @@ static int trace__run(struct trace *trace, int argc, const char **argv) trace->multiple_threads = thread_map__pid(evlist->threads, 0) == -1 || evlist->threads->nr > 1 || perf_evlist__first(evlist)->attr.inherit; + + /* + * Now that we already used evsel->attr to ask the kernel to setup the + * events, lets reuse evsel->attr.sample_max_stack as the limit in + * trace__resolve_callchain(), allowing per-event max-stack settings + * to override an explicitely set --max-stack global setting. + */ + evlist__for_each_entry(evlist, evsel) { + if ((evsel->attr.sample_type & PERF_SAMPLE_CALLCHAIN) && + evsel->attr.sample_max_stack == 0) + evsel->attr.sample_max_stack = trace->max_stack; + } again: before = trace->nr_events; -- cgit v1.2.2 From 092bd3cd7169085b09e4a5307de95e461d0581d7 Mon Sep 17 00:00:00 2001 From: Hendrik Brueckner Date: Fri, 19 Jan 2018 09:56:16 +0100 Subject: perf trace: Obtain errno strings by using arch_syscalls__strerrno() Replace the errno_to_name() from the audit-libs with the newly introduced arch_syscalls__strerrno() function. With this change: 1. With replacing errno_to_name() from audit-libs, perf trace does no longer require audit-lib interfaces. 2. In addition to 1, the audit-libs dependency can be removed for architectures that support syscall tables in perf. This is achieved in a follow-up commit. 3. With the architecture specific errno number/name mapping, perf trace reports can work across architectures. Signed-off-by: Hendrik Brueckner Reviewed-by: Thomas Richter Tested-by: Arnaldo Carvalho de Melo Cc: Jiri Olsa Cc: Michael Petlan Cc: linux-s390@vger.kernel.org LPU-Reference: 1516352177-11106-5-git-send-email-brueckner@linux.vnet.ibm.com Link: https://lkml.kernel.org/n/tip-xjvoqzhwmu4wn4kl9ng11rvs@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 531d43bf57e1..7dece5e0cdbb 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -21,6 +21,7 @@ #include "builtin.h" #include "util/color.h" #include "util/debug.h" +#include "util/env.h" #include "util/event.h" #include "util/evlist.h" #include @@ -45,14 +46,12 @@ #include #include -#include /* FIXME: Still needed for audit_errno_to_name */ #include #include #include #include #include #include -#include #include #include #include @@ -545,6 +544,7 @@ static size_t syscall_arg__scnprintf_getrandom_flags(char *bf, size_t size, { .scnprintf = SCA_STRARRAY, \ .parm = &strarray__##array, } +#include "trace/beauty/arch_errno_names.c" #include "trace/beauty/eventfd.c" #include "trace/beauty/flock.c" #include "trace/beauty/futex_op.c" @@ -1660,6 +1660,14 @@ static int trace__fprintf_callchain(struct trace *trace, struct perf_sample *sam return sample__fprintf_callchain(sample, 38, print_opts, &callchain_cursor, trace->output); } +static const char *errno_to_name(struct perf_evsel *evsel, int err) +{ + struct perf_env *env = perf_evsel__env(evsel); + const char *arch_name = perf_env__arch(env); + + return arch_syscalls__strerrno(arch_name, err); +} + static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, union perf_event *event __maybe_unused, struct perf_sample *sample) @@ -1730,7 +1738,7 @@ signed_print: errno_print: { char bf[STRERR_BUFSIZE]; const char *emsg = str_error_r(-ret, bf, sizeof(bf)), - *e = audit_errno_to_name(-ret); + *e = errno_to_name(evsel, -ret); fprintf(trace->output, ") = -1 %s %s", e, emsg); } -- cgit v1.2.2 From 591421e151ddf95e43d690a5c9b291d8e1cb8065 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 22 Jan 2018 11:38:54 -0300 Subject: perf trace: Add --print-sample To help with debugging, like the interrupted out of order issue that will be dealt with in the next patch in this series, changing the code to deal with: raw_syscalls:sys_enter 411967179.269 Timer 9609/9626 [2] raw_syscalls:sys_enter 411967179.213 file:// Content 9609/9609 [3] 328.038 (18446744073709.496 ms): Timer/9626 futex(uaddr: 0x7fc0d4027044, op: WAIT|PRIV, utime: 0x7fc0b0ffdb50 ) ... raw_syscalls:sys_exit 411967179.225 file:// Content 9609/9609 [3] 327.982 ( 0.012 ms): file:// Conten/9609 futex(uaddr: 0x7fc0d4027040, op: WAKE|PRIV, val: 1 ) = 1 That long duration is the bug. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-fljqiibjn7wet24jd1ed7abc@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 24 ++++++++++++++++++++++++ 1 file changed, 24 insertions(+) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 7dece5e0cdbb..322c2b15e407 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -110,6 +110,7 @@ struct trace { bool summary; bool summary_only; bool show_comm; + bool print_sample; bool show_tool_stats; bool trace_syscalls; bool kernel_syscallchains; @@ -1578,6 +1579,23 @@ static int trace__printf_interrupted_entry(struct trace *trace, struct perf_samp return printed; } +static int trace__fprintf_sample(struct trace *trace, struct perf_evsel *evsel, + struct perf_sample *sample, struct thread *thread) +{ + int printed = 0; + + if (trace->print_sample) { + double ts = (double)sample->time / NSEC_PER_MSEC; + + printed += fprintf(trace->output, "%22s %10.3f %s %d/%d [%d]\n", + perf_evsel__name(evsel), ts, + thread__comm_str(thread), + sample->pid, sample->tid, sample->cpu); + } + + return printed; +} + static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, union perf_event *event __maybe_unused, struct perf_sample *sample) @@ -1598,6 +1616,8 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, if (ttrace == NULL) goto out_put; + trace__fprintf_sample(trace, evsel, sample, thread); + args = perf_evsel__sc_tp_ptr(evsel, args, sample); if (ttrace->entry_str == NULL) { @@ -1688,6 +1708,8 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, if (ttrace == NULL) goto out_put; + trace__fprintf_sample(trace, evsel, sample, thread); + if (trace->summary) thread__update_stats(ttrace, id, sample); @@ -3034,6 +3056,8 @@ int cmd_trace(int argc, const char **argv) "Set the maximum stack depth when parsing the callchain, " "anything beyond the specified depth will be ignored. " "Default: kernel.perf_event_max_stack or " __stringify(PERF_MAX_STACK_DEPTH)), + OPT_BOOLEAN(0, "print-sample", &trace.print_sample, + "print the PERF_RECORD_SAMPLE PERF_SAMPLE_ info, for debugging"), OPT_UINTEGER(0, "proc-map-timeout", &trace.opts.proc_map_timeout, "per thread proc mmap processing timeout in ms"), OPT_UINTEGER('D', "delay", &trace.opts.initial_delay, -- cgit v1.2.2 From 522283fec7d3f312224360da48057e923ee22765 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 22 Jan 2018 11:42:11 -0300 Subject: perf trace: Do not print from time delta for interrupted syscall lines We were calculating the delta from a in-flight syscall that got its output interrupted by another syscall, which doesn't seem like useful information, we will print the syscall duration (sys_exit - sys_enter) when the raw_syscalls:sys_exit event happens. The problem here is how we're consuming the multiple ring buffers, without using the ordered_events code used by perf_session, which may cause some reordering of syscalls for diferent CPUs, so just stop printing that delta, to avoid things like: # trace --print-sample -p 9626 -e futex raw_syscalls:sys_enter 411967179.269 Timer 9609/9626 [2] raw_syscalls:sys_enter 411967179.213 file:// Content 9609/9609 [3] 328.038 (18446744073709.496 ms): Timer/9626 futex(uaddr: 0x7fc0d4027044, op: WAIT|PRIV, utime: 0x7fc0b0ffdb50 ) ... raw_syscalls:sys_exit 411967179.225 file:// Content 9609/9609 [3] 327.982 ( 0.012 ms): file:// Conten/9609 futex(uaddr: 0x7fc0d4027040, op: WAKE|PRIV, val: 1 ) = 1 This is a bandaid, we should better try and use the ordered_events code, possibly with some refactoring prep work, but for now at least we don't show those false long deltas for the lines ending in '...'. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-q6xgsqrju1sr6ltud9kjjhmb@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 13 +++++-------- 1 file changed, 5 insertions(+), 8 deletions(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 322c2b15e407..ab00096328e4 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -821,7 +821,7 @@ static size_t fprintf_duration(unsigned long t, bool calculated, FILE *fp) size_t printed = fprintf(fp, "("); if (!calculated) - printed += fprintf(fp, " ? "); + printed += fprintf(fp, " "); else if (duration >= 1.0) printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration); else if (duration >= 0.01) @@ -1556,10 +1556,9 @@ static void thread__update_stats(struct thread_trace *ttrace, update_stats(stats, duration); } -static int trace__printf_interrupted_entry(struct trace *trace, struct perf_sample *sample) +static int trace__printf_interrupted_entry(struct trace *trace) { struct thread_trace *ttrace; - u64 duration; size_t printed; if (trace->current == NULL) @@ -1570,9 +1569,7 @@ static int trace__printf_interrupted_entry(struct trace *trace, struct perf_samp if (!ttrace->entry_pending) return 0; - duration = sample->time - ttrace->entry_time; - - printed = trace__fprintf_entry_head(trace, trace->current, duration, true, ttrace->entry_time, trace->output); + printed = trace__fprintf_entry_head(trace, trace->current, 0, false, ttrace->entry_time, trace->output); printed += fprintf(trace->output, "%-70s) ...\n", ttrace->entry_str); ttrace->entry_pending = false; @@ -1627,7 +1624,7 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, } if (!(trace->duration_filter || trace->summary_only || trace->min_stack)) - trace__printf_interrupted_entry(trace, sample); + trace__printf_interrupted_entry(trace); ttrace->entry_time = sample->time; msg = ttrace->entry_str; @@ -1941,7 +1938,7 @@ static int trace__event_handler(struct trace *trace, struct perf_evsel *evsel, } } - trace__printf_interrupted_entry(trace, sample); + trace__printf_interrupted_entry(trace); trace__fprintf_tstamp(trace, sample->time, trace->output); if (trace->trace_syscalls) -- cgit v1.2.2 From 3258abe0991590a182be0a20ef6b79b65fe2c9cd Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 22 Jan 2018 12:56:59 -0300 Subject: perf trace beauty futex: Beautify FUTEX_BITSET_MATCH_ANY E.g.: # strace -e futex -p 14437 strace: Process 14437 attached futex(0x7f46f4808d70, FUTEX_WAKE_PRIVATE, 1) = 0 futex(0x7f46f24e68b0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, {tv_sec=1516636744, tv_nsec=221969000}, 0xffffffff) = -1 ETIMEDOUT (Connection timed out) # Should pretty print that 0xffffffff value, like: # trace -e futex --tid 14437 0.028 ( 0.005 ms): futex(uaddr: 0x7f46f4808d70, op: WAKE|PRIV, val: 1 ) = 0 0.037 (1000.092 ms): futex(uaddr: 0x7f46f24e68b0, op: WAIT_BITSET|PRIV|CLKRT, utime: 0x7f46f23fedf0, val3: MATCH_ANY) = -1 ETIMEDOUT Connection timed out ^C# Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-raef6e352la90600yksthao1@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index ab00096328e4..46d3ff09440c 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -549,6 +549,7 @@ static size_t syscall_arg__scnprintf_getrandom_flags(char *bf, size_t size, #include "trace/beauty/eventfd.c" #include "trace/beauty/flock.c" #include "trace/beauty/futex_op.c" +#include "trace/beauty/futex_val3.c" #include "trace/beauty/mmap.c" #include "trace/beauty/mode_t.c" #include "trace/beauty/msg_flags.c" @@ -611,7 +612,8 @@ static struct syscall_fmt { { .name = "fstat", .alias = "newfstat", }, { .name = "fstatat", .alias = "newfstatat", }, { .name = "futex", - .arg = { [1] = { .scnprintf = SCA_FUTEX_OP, /* op */ }, }, }, + .arg = { [1] = { .scnprintf = SCA_FUTEX_OP, /* op */ }, + [5] = { .scnprintf = SCA_FUTEX_VAL3, /* val3 */ }, }, }, { .name = "futimesat", .arg = { [0] = { .scnprintf = SCA_FDAT, /* fd */ }, }, }, { .name = "getitimer", -- cgit v1.2.2 From bafae98e7a95df74ce4529ae96251cb12c86fdf3 Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 22 Jan 2018 16:42:16 -0300 Subject: perf evlist: Remove fcntl.h from evlist.h Not needed there, fixup the places where it is needed and was getting only by luck via evlist.h. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-yxjpetn64z8vjuguu84gr6x6@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 1 + 1 file changed, 1 insertion(+) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 46d3ff09440c..868306ccd8b8 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -56,6 +56,7 @@ #include #include #include +#include #include "sane_ctype.h" -- cgit v1.2.2 From c19d0847b2dce3dc4219fa1a21f4ad2256b42d9d Mon Sep 17 00:00:00 2001 From: Arnaldo Carvalho de Melo Date: Mon, 22 Jan 2018 16:50:16 -0300 Subject: perf trace beauty flock: Move to separate object file To resolve some header conflicts that were preventing the build to succeed in the Alpine Linux distribution. Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-bvud0dvzvip3kibeplupdbmc@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/builtin-trace.c | 1 - 1 file changed, 1 deletion(-) (limited to 'tools/perf/builtin-trace.c') diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 868306ccd8b8..17d11deeb88d 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -548,7 +548,6 @@ static size_t syscall_arg__scnprintf_getrandom_flags(char *bf, size_t size, #include "trace/beauty/arch_errno_names.c" #include "trace/beauty/eventfd.c" -#include "trace/beauty/flock.c" #include "trace/beauty/futex_op.c" #include "trace/beauty/futex_val3.c" #include "trace/beauty/mmap.c" -- cgit v1.2.2