Re: [PATCH v4 3/3] perf report: support hotkey to let user select any event for sorting

From: Jin, Yao
Date: Thu Dec 19 2019 - 00:10:38 EST



On 12/19/2019 9:14 AM, Jin, Yao wrote:


On 12/18/2019 3:47 PM, Jiri Olsa wrote:
On Wed, Dec 18, 2019 at 10:24:43AM +0800, Jin Yao wrote:
When performing "perf report --group", it shows the event group information
together. In previous patch, we have supported a new option "--group-sort-idx"
to sort the output by the event at the index n in event group.

It would be nice if we can use a hotkey in browser to select a event
to sort.

For example,

ÂÂ # perf report --group

 Samples: 12K of events 'cpu/instructions,period=2000003/, cpu/cpu-cycles,period=200003/, ...
 Overhead Command Shared Object Symbol
ÂÂ 92.19%Â 98.68%ÂÂ 0.00%Â 93.30%Â mgen mgenÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ [.] LOOP1
ÂÂÂ 3.12%ÂÂ 0.29%ÂÂ 0.00%ÂÂ 0.16%Â gsd-color libglib-2.0.so.0.5600.4Â [.] 0x0000000000049515
ÂÂÂ 1.56%ÂÂ 0.03%ÂÂ 0.00%ÂÂ 0.04%Â gsd-color libglib-2.0.so.0.5600.4Â [.] 0x00000000000494b7
ÂÂÂ 1.56%ÂÂ 0.01%ÂÂ 0.00%ÂÂ 0.00%Â gsd-color libglib-2.0.so.0.5600.4Â [.] 0x00000000000494ce
ÂÂÂ 1.56%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%Â mgen [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] task_tick_fair
ÂÂÂ 0.00%ÂÂ 0.15%ÂÂ 0.00%ÂÂ 0.04%Â perf [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] smp_call_function_single
ÂÂÂ 0.00%ÂÂ 0.13%ÂÂ 0.00%ÂÂ 6.08%Â swapper [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] intel_idle
ÂÂÂ 0.00%ÂÂ 0.03%ÂÂ 0.00%ÂÂ 0.00%Â gsd-color libglib-2.0.so.0.5600.4Â [.] g_main_context_check
ÂÂÂ 0.00%ÂÂ 0.03%ÂÂ 0.00%ÂÂ 0.00%Â swapper [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] apic_timer_interrupt
ÂÂÂ 0.00%ÂÂ 0.03%ÂÂ 0.00%ÂÂ 0.00%Â swapper [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] check_preempt_curr

When user press hotkey '3' (event index, starting from 0), it indicates
to sort output by the forth event in group.

ÂÂ Samples: 12K of events 'cpu/instructions,period=2000003/, cpu/cpu-cycles,period=200003/, ...
 Overhead Command Shared Object Symbol
ÂÂ 92.19%Â 98.68%ÂÂ 0.00%Â 93.30%Â mgen mgenÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ [.] LOOP1
ÂÂÂ 0.00%ÂÂ 0.13%ÂÂ 0.00%ÂÂ 6.08%Â swapper [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] intel_idle
ÂÂÂ 3.12%ÂÂ 0.29%ÂÂ 0.00%ÂÂ 0.16%Â gsd-color libglib-2.0.so.0.5600.4Â [.] 0x0000000000049515
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.06%Â swapper [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] hrtimer_start_range_ns
ÂÂÂ 1.56%ÂÂ 0.03%ÂÂ 0.00%ÂÂ 0.04%Â gsd-color libglib-2.0.so.0.5600.4Â [.] 0x00000000000494b7
ÂÂÂ 0.00%ÂÂ 0.15%ÂÂ 0.00%ÂÂ 0.04%Â perf [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] smp_call_function_single
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.02%Â mgen [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] update_curr
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.02%Â mgen [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] apic_timer_interrupt
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.02%Â mgen [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] native_apic_msr_eoi_write
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.02%Â mgen [kernel.kallsyms]ÂÂÂÂÂÂÂ [k] __update_load_avg_se

when I press 0...9 I'm getting extra columns:

Samples: 134Â of events 'anon group { cycles:u, instructions:u, cache-misses:u, cycles:u, instructions:u }', Event count (approx.): 7107344
 Overhead Command Shared Object Symbol Self
ÂÂ 17.95%Â 41.20%ÂÂ 0.00%Â 12.44%Â 41.30%Â lsÂÂÂÂÂÂ libc-2.29.so [.] __strcoll_lÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 17.95%Â 41.20%ÂÂ 0.00%Â 12.44% 41.30%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%Â 13.22%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ls [.] 0x000000000000871cÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%Â 13.22%ÂÂ 0.00%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 8.32%Â 11.49%ÂÂ 0.00%ÂÂ 2.62%ÂÂ 9.34%Â lsÂÂÂÂÂÂ ld-2.29.so [.] do_lookup_xÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 8.32%Â 11.49%ÂÂ 0.00%ÂÂ 2.62% 9.34%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 8.29%Â 31.18%Â 13.34%ÂÂ 3.05%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_lookup_symbol_xÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 8.29%Â 31.18%Â 13.34% 3.05%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 6.47%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ libc-2.29.so [.] __strlen_avx2ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 6.47%ÂÂ 0.00%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 5.97%ÂÂ 0.00%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ls [.] 0x0000000000014001ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 5.97%ÂÂ 0.00%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 5.77%ÂÂ 5.83%ÂÂ 7.79%ÂÂ 4.78%ÂÂ 5.04%Â lsÂÂÂÂÂÂ ld-2.29.so [.] strcmpÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 5.77%ÂÂ 5.83%ÂÂ 7.79%ÂÂ 4.78% 5.04%ÂÂÂÂÂÂ N/A
ÂÂÂ 2.31%ÂÂ 4.35%ÂÂ 8.30%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_map_object_from_fdÂÂÂÂÂÂÂÂÂÂÂÂ 2.31%ÂÂ 4.35%ÂÂ 8.30%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 2.96%ÂÂ 0.00%ÂÂ 1.30%ÂÂ 2.22%Â lsÂÂÂÂÂÂ ld-2.29.so [.] __GI___tunables_initÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 2.96%ÂÂ 0.00%ÂÂ 1.30% 2.22%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.66%ÂÂ 0.22%ÂÂ 0.68%ÂÂ 0.00%ÂÂ 0.21%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_startÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.66%ÂÂ 0.22%ÂÂ 0.68%ÂÂ 0.00% 0.21%ÂÂÂÂÂÂ N/A
ÂÂÂ 2.42%ÂÂ 0.00%ÂÂ 0.02%ÂÂ 3.16%ÂÂ 0.00%Â lsÂÂÂÂÂÂ [unknown] [k] 0xffffffffa2a012b0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 2.42%ÂÂ 0.00%ÂÂ 0.02%ÂÂ 3.16% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.16%ÂÂ 0.00%ÂÂ 0.01%ÂÂ 0.20%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _startÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.16%ÂÂ 0.00%ÂÂ 0.01%ÂÂ 0.20% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 0.00%Â 11.47%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ libcap.so.2.26 [.] 0x0000000000002420ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 0.00%Â 11.47%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 0.00%Â 10.50%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ libc-2.29.so [.] __GI___tcgetattrÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 0.00%Â 10.50%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 9.14%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ls [.] 0x000000000000767aÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 9.14%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂ 13.60%ÂÂ 0.00%ÂÂ 7.14%ÂÂ 2.31%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_relocate_objectÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 13.60%ÂÂ 0.00%ÂÂ 7.14%ÂÂ 2.31% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 2.13%ÂÂ 0.00%ÂÂ 6.14%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_map_object_depsÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 2.13%ÂÂ 0.00%ÂÂ 6.14%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 5.27%ÂÂ 0.00%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] strlenÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 0.00%ÂÂ 0.00%ÂÂ 5.27%ÂÂ 0.00% 0.00%ÂÂÂÂÂÂ N/A
ÂÂÂ 1.31%ÂÂ 0.00%ÂÂ 2.37%ÂÂ 1.08%ÂÂ 0.00%Â lsÂÂÂÂÂÂ ld-2.29.so [.] _dl_sysdep_startÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 1.31%ÂÂ 0.00%ÂÂ 2.37%ÂÂ 1.08% 0.00%ÂÂÂÂÂÂ N/A


jirka


Looks it's an existing issue in perf. We can reproduce it by following steps.

1. perf record -a -e cycles,instructions -- sleep 3
2. perf report --group
3. In browser, we use hotkey 's' to switch to another perf.data
4. Now in browser, the extra columns 'Self' and 'Children' will be shown.

But I have not figured out which patch caused this issue. :(

Thanks
Jin Yao

I have debugged this issue and I find that's because setup_sorting() is executed again after repeat path, so dimensions are added again.

Could you help to review following fix? Thanks!

diff --git a/tools/perf/builtin-report.c b/tools/perf/builtin-report.c
index 387311c67264..de988589d99b 100644
--- a/tools/perf/builtin-report.c
+++ b/tools/perf/builtin-report.c
@@ -1076,6 +1076,7 @@ int cmd_report(int argc, const char **argv)
struct stat st;
bool has_br_stack = false;
int branch_mode = -1;
+ int last_key = 0;
bool branch_call_mode = false;
#define CALLCHAIN_DEFAULT_OPT "graph,0.5,caller,function,percent"
static const char report_callchain_help[] = "Display call graph (stack chain/backtrace):\n\n"
@@ -1450,7 +1451,8 @@ int cmd_report(int argc, const char **argv)
sort_order = sort_tmp;
}

- if (setup_sorting(session->evlist) < 0) {
+ if ((last_key != K_SWITCH_INPUT_DATA) &&
+ (setup_sorting(session->evlist) < 0)) {
if (sort_order)
parse_options_usage(report_usage, options, "s", 1);
if (field_order)
@@ -1530,6 +1532,7 @@ int cmd_report(int argc, const char **argv)
ret = __cmd_report(&report);
if (ret == K_SWITCH_INPUT_DATA) {
perf_session__delete(session);
+ last_key = K_SWITCH_INPUT_DATA;
goto repeat;
} else
ret = 0;

Thanks
Jin Yao