| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Mon, 3 Sep 2018 08:44:08 -0700
From: Andi Kleen <ak@...ux.intel.com>
To: Jiri Olsa <jolsa@...hat.com>
Cc: Andi Kleen <andi@...stfloor.org>, acme@...nel.org,
jolsa@...nel.org, linux-kernel@...r.kernel.org
Subject: Re: [PATCH v2 10/10] tools, perf, script: Implement --graph-function
On Mon, Sep 03, 2018 at 09:51:28AM +0200, Jiri Olsa wrote:
> On Fri, Aug 31, 2018 at 03:02:06PM -0700, Andi Kleen wrote:
> > From: Andi Kleen <ak@...ux.intel.com>
> >
> > Add a ftrace style --graph-function argument to perf script that allows
> > to print itrace function calls only below a given function. This
> > makes it easier to find the code of interest in a large trace.
> >
> > % perf record -e intel_pt//k -a sleep 1
> > % perf script --graph-function group_sched_in --call-trace
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) group_sched_in
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) event_sched_in.isra.107
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_set_state.part.71
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_time
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_disable
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_log_itrace_start
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_event_update_userpage
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) calc_timer_values
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) sched_clock_cpu
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) arch_perf_update_userpage
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __fentry__
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) using_native_sched_clock
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) sched_clock_stable
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) perf_pmu_enable
> > perf 900 [000] 194167.205652203: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) group_sched_in
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) event_sched_in.isra.107
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_set_state.part.71
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_update_time
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_pmu_disable
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_log_itrace_start
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) perf_event_update_userpage
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) calc_timer_values
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) sched_clock_cpu
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __x86_indirect_thunk_rax
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) arch_perf_update_userpage
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) __fentry__
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) using_native_sched_clock
> > swapper 0 [001] 194167.205660693: ([kernel.kallsyms]) sched_clock_stable
>
> nice, but I'm also getting a lot of these lines:
>
> instruction trace error type 1 cpu 0 pid 0 tid 0 ip 0xffffffffb3a017a0 code 6: Trace doesn't match instruction
> instruction trace error type 1 cpu 0 pid 0 tid 0 ip 0xffffffffb3a017a0 code 6: Trace doesn't match instruction
> instruction trace error type 1 cpu 0 pid 0 tid 0 ip 0xffffffffb3a017a0 code 6: Trace doesn't match instruction
>
> any idea where are those comming from?
PT decoder didn't see the same instructions as during the trace collection.
There are many reasons which can cause this, usually (but not always) some form of
self modifying code. The Linux kernel does a lot of self modification these days,
which is a challenge for PT.
If you run the decoder as root it will decode from /proc/kcore, which helps, but
only if no jump label has changed state since the collection.
The perf PT decoder tends to resync relatively quickly, so usually not too much
is lost.
-Andi
Powered by blists - more mailing lists