diff options
author | Milian Wolff <milian.wolff@kdab.com> | 2018-10-21 21:14:24 +0200 |
---|---|---|
committer | Arnaldo Carvalho de Melo <acme@redhat.com> | 2018-10-22 19:27:11 +0200 |
commit | 7ee40678af935fb489b0c6cf0f75808175214cd7 (patch) | |
tree | 6af2e80f98ec781fb4577b18392540e0035721c9 /tools/perf/builtin-script.c | |
parent | perf script: Allow extended console debug output (diff) | |
download | linux-7ee40678af935fb489b0c6cf0f75808175214cd7.tar.xz linux-7ee40678af935fb489b0c6cf0f75808175214cd7.zip |
perf script: Flush output stream after events in verbose mode
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>
Diffstat (limited to '')
-rw-r--r-- | tools/perf/builtin-script.c | 3 |
1 files changed, 3 insertions, 0 deletions
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; |