Re: Broken kretprobe stack traces

[Daniel Xu]

On Wed, Mar 03, 2021 at 01:48:28PM +0900, Masami Hiramatsu wrote:
> Hi Daniel,
> 
> On Tue, 02 Mar 2021 17:15:13 -0800
> "Daniel Xu" <dxu@xxxxxxxxx> wrote:
> 
> > Hi Masami,
> > 
> > Jakub reported a bug with kretprobe stack traces -- wondering if you've gotten
> > any bug reports related to stack traces being broken for kretprobes.
> 
> Yeah, stack dumper must check the stack entry is kretprobe'd and skip it.
> For example, ftrace checks it as below.
> 
> /sys/kernel/debug/tracing # echo r vfs_read > kprobe_events 
> /sys/kernel/debug/tracing # echo stacktrace > events/kprobes/r_vfs_read_0/trigger 
> /sys/kernel/debug/tracing # echo 1 > events/kprobes/r_vfs_read_0/enable 
> /sys/kernel/debug/tracing # head -20 trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 15685/336094   #P:8
> #
> #                                _-----=> irqs-off
> #                               / _----=> need-resched
> #                              | / _---=> hardirq/softirq
> #                              || / _--=> preempt-depth
> #                              ||| /     delay
> #           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
> #              | |         |   ||||      |         |
>               sh-132     [006] ...1    38.920352: <stack trace>
>  => kretprobe_dispatcher
>  => __kretprobe_trampoline_handler
>  => trampoline_handler
>  => [unknown/kretprobe'd]
>  => [unknown/kretprobe'd]
>  => __x64_sys_read
>  => do_syscall_64
>  => entry_SYSCALL_64_after_hwframe
> 
> 
> > 
> > I think (can't prove) this used to work:
> 
> I'm not sure the bpftrace had correctly handled it or not.
> 
> > 
> >     # bpftrace -e 'kretprobe:__tcp_retransmit_skb { @[kstack()] = count() }'
> >     Attaching 1 probe...
> >     ^C
> > 
> >     @[
> >         kretprobe_trampoline+0
> >     ]: 1
> 
> Would you know how the bpftrace stacktracer rewinds the stack entries?
> FYI, ftrace does it in trace_seq_print_sym()@kernel/trace/trace_output.c

Thanks for the hint, I'll take a look.

bpftrace generates a bpf program that calls into the kernel's
bpf_get_stackid():

https://github.com/torvalds/linux/blob/f69d02e37a85645aa90d18cacfff36dba370f797/include/uapi/linux/bpf.h#L1296

so it could be a bug with bpf.

<...>