All of lore.kernel.org
 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:10 UTC|newest]

Thread overview: 41+ 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 ` 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
2018-10-26  7:25   ` 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 \
    /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
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.