From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753549AbdGUHot (ORCPT ); Fri, 21 Jul 2017 03:44:49 -0400 Received: from mx1.redhat.com ([209.132.183.28]:35316 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752433AbdGUHor (ORCPT ); Fri, 21 Jul 2017 03:44:47 -0400 DMARC-Filter: OpenDMARC Filter v1.3.2 mx1.redhat.com 82E5B25CD9 Authentication-Results: ext-mx01.extmail.prod.ext.phx2.redhat.com; dmarc=none (p=none dis=none) header.from=redhat.com Authentication-Results: ext-mx01.extmail.prod.ext.phx2.redhat.com; spf=pass smtp.mailfrom=jolsa@redhat.com DKIM-Filter: OpenDKIM Filter v2.11.0 mx1.redhat.com 82E5B25CD9 Date: Fri, 21 Jul 2017 09:44:44 +0200 From: Jiri Olsa To: David Carrillo-Cisneros Cc: linux-kernel@vger.kernel.org, Ingo Molnar , Arnaldo Carvalho de Melo , Alexander Shishkin , Andi Kleen , Simon Que , Wang Nan , Jiri Olsa , Namhyung Kim , Stephane Eranian , Paul Turner Subject: Re: [PATCH] perf tool sort: Use default sort if evlist is empty Message-ID: <20170721074444.GB29613@krava> References: <20170721051157.47331-1-davidcc@google.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20170721051157.47331-1-davidcc@google.com> User-Agent: Mutt/1.8.3 (2017-05-23) X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.25]); Fri, 21 Jul 2017 07:44:47 +0000 (UTC) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, Jul 20, 2017 at 10:11:57PM -0700, David Carrillo-Cisneros wrote: > Fixes bug noted by Jiri in https://lkml.org/lkml/2017/6/13/755 and caused > by commit d49dadea7862 ("perf tools: Make 'trace' or 'trace_fields' sort > key default for tracepoint events") > not taking into account that evlist is empty in pipe-mode. > > Before this commit, pipe mode will only show bogus "100.00% N/A" instead > of correct output as follows: > > $ perf record -o - sleep 1 | perf report -i - > # To display the perf.data header info, please use --header/--header-only options. > # > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.000 MB - ] > # > # Total Lost Samples: 0 > # > # Samples: 8 of event 'cycles:ppH' > # Event count (approx.): 145658 > # > # Overhead Trace output > # ........ ............ > # > 100.00% N/A > > Correct output, after patch: > > $ perf record -o - sleep 1 | perf report -i - > # To display the perf.data header info, please use --header/--header-only options. > # > [ perf record: Woken up 1 times to write data ] > [ perf record: Captured and wrote 0.000 MB - ] > # > # Total Lost Samples: 0 > # > # Samples: 8 of event 'cycles:ppH' > # Event count (approx.): 191331 > # > # Overhead Command Shared Object Symbol > # ........ ....... ................. ................................. > # > 81.63% sleep libc-2.19.so [.] _exit > 13.58% sleep ld-2.19.so [.] do_lookup_x > 2.34% sleep [kernel.kallsyms] [k] context_switch > 2.34% sleep libc-2.19.so [.] __GI___libc_nanosleep > 0.11% perf [kernel.kallsyms] [k] __intel_pmu_enable_a > I wonder we could reinit the sortorder once we know what events we have in pipe, and recognize the tracepoint output properly: [root@krava perf]# ./perf record -e 'sched:sched_switch' sleep 1 | ./perf report # To display the perf.data header info, please use --header/--header-only options. SNIP # # Overhead Command Shared Object Symbol # ........ ....... ................. .............. # 100.00% sleep [kernel.kallsyms] [k] __schedule also I've got another crash for (added -a option for above example): [root@krava perf]# ./perf record -e 'sched:sched_switch' -a sleep 1 | ./perf report # To display the perf.data header info, please use --header/--header-only options. # [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.000 MB (null) ] Segmentation fault (core dumped) catchsegv got: /home/jolsa/kernel/linux-perf/tools/perf/util/ordered-events.c:85(free_dup_event)[0x51a6a5] ./perf(ordered_events__free+0x5c)[0x51b0b7] /home/jolsa/kernel/linux-perf/tools/perf/util/session.c:1751(__perf_session__process_pipe_events)[0x518abb] ./perf(perf_session__process_events+0x91)[0x5190f0] /home/jolsa/kernel/linux-perf/tools/perf/builtin-report.c:598(__cmd_report)[0x443a91] ./perf(cmd_report+0x169b)[0x4455a3] /home/jolsa/kernel/linux-perf/tools/perf/perf.c:296(run_builtin)[0x4be1b0] /home/jolsa/kernel/linux-perf/tools/perf/perf.c:348(handle_internal_command)[0x4be41d] /home/jolsa/kernel/linux-perf/tools/perf/perf.c:395(run_argv)[0x4be56f] ./perf(main+0x2d6)[0x4be949] /lib64/libc.so.6(__libc_start_main+0xf1)[0x7f3de8a10401] ./perf(_start+0x2a)[0x42831a] looks like some mem corruption.. will try to follow up on this later if nobody beats me to it ;-) thanks, jirka