Re: 4.19 dwarf unwinding broken

From: Arnaldo Carvalho de Melo
Date: Thu Oct 03 2019 - 12:04:38 EST


Em Thu, Oct 03, 2019 at 08:17:38AM -0700, Josh Hunt escreveu:
> On 10/3/19 3:03 AM, Jiri Olsa wrote:
> >On Thu, Oct 03, 2019 at 12:54:09AM -0700, Josh Hunt wrote:
> >>The following commit is breaking dwarf unwinding on 4.19 kernels:
> >
> >how?
>
> When doing something like:
> perf record -p $(cat /var/run/app.pid) -g --call-graph dwarf -F 999
> -- sleep 3
>
> with 4.19.75 perf I see things like:
>
> app_Thr00 26247 1810131.375329: 168288 cycles:ppp:
>
> app_Thr01 26767 1810131.377449: 344415 cycles:ppp:
>
> uvm:WorkerThread 26746 1810131.383052: 504 cycles:ppp:
> ffffffff9f77cce0 _raw_spin_lock+0x10 (/boot/vmlinux-4.19.46)
> ffffffff9f181527 __perf_event_task_sched_in+0xf7
> (/boot/vmlinux-4.19.46)
> ffffffff9f09a7b8 finish_task_switch+0x158 (/boot/vmlinux-4.19.46)
> ffffffff9f778276 __schedule+0x2f6 (/boot/vmlinux-4.19.46)
> ffffffff9f7787f2 schedule+0x32 (/boot/vmlinux-4.19.46)
> ffffffff9f77bb0a schedule_hrtimeout_range_clock+0x8a
> (/boot/vmlinux-4.19.46)
> ffffffff9f22ea12 poll_schedule_timeout.constprop.6+0x42
> (/boot/vmlinux-4.19.46)
> ffffffff9f22eeeb do_sys_poll+0x4ab (/boot/vmlinux-4.19.46)
> ffffffff9f22fb7b __se_sys_poll+0x5b (/boot/vmlinux-4.19.46)
> ffffffff9f0023de do_syscall_64+0x4e (/boot/vmlinux-4.19.46)
> ffffffff9f800088 entry_SYSCALL_64+0x68 (/boot/vmlinux-4.19.46)
> ---
>
> and with 4.19.75 perf with e5adfc3e7e77 reverted those empty call
> stacks go away and also other call stacks show more thread details:
>
> uvm:WorkerThread 26746 1810207.336391: 1 cycles:ppp:
> ffffffff9f181505 __perf_event_task_sched_in+0xd5
> (/boot/vmlinux-4.19.46)
> ffffffff9f09a7b8 finish_task_switch+0x158 (/boot/vmlinux-4.19.46)
> ffffffff9f778276 __schedule+0x2f6 (/boot/vmlinux-4.19.46)
> ffffffff9f7787f2 schedule+0x32 (/boot/vmlinux-4.19.46)
> ffffffff9f77bb0a schedule_hrtimeout_range_clock+0x8a
> (/boot/vmlinux-4.19.46)
> ffffffff9f22ea12 poll_schedule_timeout.constprop.6+0x42
> (/boot/vmlinux-4.19.46)
> ffffffff9f22eeeb do_sys_poll+0x4ab (/boot/vmlinux-4.19.46)
> ffffffff9f22fb7b __se_sys_poll+0x5b (/boot/vmlinux-4.19.46)
> ffffffff9f0023de do_syscall_64+0x4e (/boot/vmlinux-4.19.46)
> ffffffff9f800088 entry_SYSCALL_64+0x68 (/boot/vmlinux-4.19.46)
> 7f7ef3f5c90d [unknown] (/lib/x86_64-linux-gnu/libc-2.23.so)
> 3eb5c99 poll+0xc9 (inlined)
> 3eb5c99 colib::ipc::EventFd::wait+0xc9
> (/usr/local/bin/app)
> 3296779 uvm::WorkerThread::run+0x129 (/usr/local/bin/app)
> ffffffffffffffff [unknown] ([unknown])
>
> They also look the same as earlier kernel versions we have running.
>
> In addition reading e8ba2906f6b's changelog sounded very similar to
> what I was seeing. This application launches a # of threads and is
> definitely already running before the invocation of perf.
>
> Thanks for looking at this.


So, if at __event__synthesize_thread()


if (pid == tgid &&
perf_event__synthesize_mmap_events(tool, mmap_event, pid, tgid,
process, machine, mmap_data))


We did something like:

if (pid != tgid && machine__find_thread(tgid, tgid) == NULL) {
struct thread *t = thread__new(tgid, tgid);

then use the info for pid to get synthesize the thread
group leader so that the get the sharing we need?
}


- Arnaldo