linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Arnaldo Carvalho de Melo <acme@kernel.org>
To: Ingo Molnar <mingo@kernel.org>
Cc: Clark Williams <williams@redhat.com>,
	linux-kernel@vger.kernel.org, linux-perf-users@vger.kernel.org,
	Milian Wolff <milian.wolff@kdab.com>,
	Arnaldo Carvalho de Melo <acme@redhat.com>
Subject: [PATCH 14/37] perf script: Flush output stream after events in verbose mode
Date: Thu, 25 Oct 2018 08:10:08 -0300	[thread overview]
Message-ID: <20181025111031.3440-15-acme@kernel.org> (raw)
In-Reply-To: <20181025111031.3440-1-acme@kernel.org>

From: Milian Wolff <milian.wolff@kdab.com>

When the perf script output is written to a terminal stream, the normal
output of `perf script` would get buffered, but its debug output would
be written directly. This made it quite hard to figure out where a given
debug output is coming from.

We can improve on this by flushing the output buffer after processing an
event. To see the value, compare the following output for a `perf script
-v` run:

Before this patch:
```
unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
unwind: find_proc_info dso /usr/lib/ld-2.28.so
unwind: reg 6, val 0
unwind: _start:ip = 0x7faf7dfdc000 (0x2000)
unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
unwind: find_proc_info dso /usr/lib/ld-2.28.so
unwind: reg 6, val 0
unwind: _start:ip = 0x7faf7dfdc000 (0x2000)
unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
unwind: find_proc_info dso /usr/lib/ld-2.28.so
unwind: reg 6, val 0
unwind: _start:ip = 0x7faf7dfdc000 (0x2000)
unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
... lots and lots of verbose debug output
cpp-inlining 24617 90229.122036534:          1 cycles:uppp:
            7faf7dfdc000 _start+0x0 (/usr/lib/ld-2.28.so)

cpp-inlining 24617 90229.122043974:          1 cycles:uppp:
            7faf7dfdc000 _start+0x0 (/usr/lib/ld-2.28.so)
...
```

After this patch:
```
...
unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
unwind: find_proc_info dso /usr/lib/ld-2.28.so
unwind: reg 6, val 0
unwind: _start:ip = 0x7faf7dfdc000 (0x2000)
cpp-inlining 24617 90229.122036534:          1 cycles:uppp:
            7faf7dfdc000 _start+0x0 (/usr/lib/ld-2.28.so)

unwind: reg 16, val 7faf7dfdc000
unwind: reg 7, val 7ffc80811e30
unwind: find_proc_info dso /usr/lib/ld-2.28.so
unwind: reg 6, val 0
unwind: _start:ip = 0x7faf7dfdc000 (0x2000)
cpp-inlining 24617 90229.122043974:          1 cycles:uppp:
            7faf7dfdc000 _start+0x0 (/usr/lib/ld-2.28.so)
...
```

This new output format makes it much easier to use perf script output
for debugging purposes, e.g. to investigate broken dwarf unwinding.

Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Acked-by: Jiri Olsa <jolsa@kernel.org>
Link: http://lkml.kernel.org/r/20181021191424.16183-2-milian.wolff@kdab.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/builtin-script.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index bd468b90801b..ca09b7d2adb7 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -1737,6 +1737,9 @@ static void process_event(struct perf_script *script,
 
 	if (PRINT_FIELD(METRIC))
 		perf_sample__fprint_metric(script, thread, evsel, sample, fp);
+
+	if (verbose)
+		fflush(fp);
 }
 
 static struct scripting_ops	*scripting_ops;
-- 
2.14.4


  parent reply	other threads:[~2018-10-25 11:11 UTC|newest]

Thread overview: 39+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2018-10-25 11:09 [PATCH 00/37] perf/core improvements and fixes Arnaldo Carvalho de Melo
2018-10-25 11:09 ` [PATCH 01/37] perf record: Encode -k clockid frequency into Perf trace Arnaldo Carvalho de Melo
2018-10-25 11:09 ` [PATCH 02/37] perf annotate: Add Sparc support Arnaldo Carvalho de Melo
2018-10-25 11:09 ` [PATCH 03/37] perf jitdump: " Arnaldo Carvalho de Melo
2018-10-25 11:09 ` [PATCH 04/37] perf symbols: Set PLT entry/header sizes properly on Sparc Arnaldo Carvalho de Melo
2018-10-25 11:09 ` [PATCH 05/37] perf arm64: Fix generate system call table failed with /tmp mounted with noexec Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 06/37] tools lib subcmd: Introduce OPTION_ULONG Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 07/37] perf trace: Introduce --max-events Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 08/37] perf evsel: Introduce per event max_events property Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 09/37] perf evsel: Mark a evsel as disabled when asking the kernel do disable it Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 10/37] perf trace: Drop addr_location refcounts Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 11/37] perf trace: Drop thread refcount in trace__event_handler() Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 12/37] perf stat: Poll for monitored tasks being alive Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 13/37] perf script: Allow extended console debug output Arnaldo Carvalho de Melo
2018-10-25 11:10 ` Arnaldo Carvalho de Melo [this message]
2018-10-25 11:10 ` [PATCH 15/37] perf trace: Introduce per-event maximum number of events property Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 16/37] perf scripts python: call-graph-from-sql.py: Use SPDX license identifier Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 17/37] perf scripts python: call-graph-from-sql.py: Provide better default column sizes Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 18/37] perf scripts python: call-graph-from-sql.py: Set a minimum window size Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 19/37] perf scripts python: call-graph-from-sql.py: Change icon Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 20/37] perf scripts python: call-graph-from-sql.py: Make a "Main" function Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 21/37] perf scripts python: call-graph-from-sql.py: Separate the database details into a class Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 22/37] perf scripts python: call-graph-from-sql.py: Add a class for global data Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 23/37] perf scripts python: call-graph-from-sql.py: Remove use of setObjectName() Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 24/37] perf scripts python: call-graph-from-sql.py: Factor out CallGraphModel from TreeModel Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 25/37] perf scripts python: call-graph-from-sql.py: Add data helper functions Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 26/37] perf scripts python: call-graph-from-sql.py: Refactor TreeItem class Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 27/37] perf scripts python: call-graph-from-sql.py: Rename to exported-sql-viewer.py Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 28/37] perf scripts python: exported-sql-viewer.py: Add support for multiple sub-windows Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 29/37] perf scripts python: exported-sql-viewer.py: Add ability to find symbols in the call-graph Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 30/37] perf scripts python: exported-sql-viewer.py: Add ability to shrink / enlarge font Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 31/37] perf scripts python: exported-sql-viewer.py: Add ability to display all the database tables Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 32/37] perf scripts python: exported-sql-viewer.py: Add All branches report Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 33/37] perf script: Add --insn-trace for instruction decoding Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 34/37] perf script: Make itrace script default to all calls Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 35/37] tools script: Add --call-trace and --call-ret-trace Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 36/37] perf script: Implement --graph-function Arnaldo Carvalho de Melo
2018-10-25 11:10 ` [PATCH 37/37] perf script: Support total cycles count Arnaldo Carvalho de Melo
2018-10-26  7:25 ` [PATCH 00/37] perf/core improvements and fixes Ingo Molnar

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20181025111031.3440-15-acme@kernel.org \
    --to=acme@kernel.org \
    --cc=acme@redhat.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-perf-users@vger.kernel.org \
    --cc=milian.wolff@kdab.com \
    --cc=mingo@kernel.org \
    --cc=williams@redhat.com \
    --subject='Re: [PATCH 14/37] perf script: Flush output stream after events in verbose mode' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).