Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-30 Thread Milian Wolff
On Montag, 29. Oktober 2018 18:40:14 CET Arnaldo Carvalho de Melo wrote:
> Em Mon, Oct 29, 2018 at 04:26:27PM +0100, Milian Wolff escreveu:
> > On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> > > Libdwfl parses an ELF file itself and creates mappings for the
> > > individual sections. Perf on the other hand sees raw mmap events which
> > > represent individual sections. When we encounter an address pointing
> > > into a mapping with pgoff != 0, we must take that into account and
> > > report the file at the non-offset base address.
> > 
> > > This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> > 
> > 
> > > Note that the backtrace is still stopping too early, when
> > > compared to the nice results obtained via libunwind. It's
> > > unclear so far what the reason for that is.
> > 
> > The remaining issue is due to a bug in elfutils:
> > 
> > https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html
> > 
> > With both patches applied, libunwind and elfutils produce the same output
> > for the above scenario.
> 
> I'm updating the patch to remove:
> 
> "It's unclear so far what the reason for that is."
> 
> Adding:
> 
> "See https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html for
> a patch fixing that."
> 
> Ok?

Yes, thanks. I figured the fix for elfutils out after I submitted the perf 
patch.

> Or are you saying that that "unclear" part applies to both libunwind
> and elfutils?

No, libunwind worked fine without these patches for this specific case.

Cheers

-- 
Milian Wolff | milian.wo...@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt, C++ and OpenGL Experts

smime.p7s
Description: S/MIME cryptographic signature


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-30 Thread Milian Wolff
On Montag, 29. Oktober 2018 18:40:14 CET Arnaldo Carvalho de Melo wrote:
> Em Mon, Oct 29, 2018 at 04:26:27PM +0100, Milian Wolff escreveu:
> > On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> > > Libdwfl parses an ELF file itself and creates mappings for the
> > > individual sections. Perf on the other hand sees raw mmap events which
> > > represent individual sections. When we encounter an address pointing
> > > into a mapping with pgoff != 0, we must take that into account and
> > > report the file at the non-offset base address.
> > 
> > > This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> > 
> > 
> > > Note that the backtrace is still stopping too early, when
> > > compared to the nice results obtained via libunwind. It's
> > > unclear so far what the reason for that is.
> > 
> > The remaining issue is due to a bug in elfutils:
> > 
> > https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html
> > 
> > With both patches applied, libunwind and elfutils produce the same output
> > for the above scenario.
> 
> I'm updating the patch to remove:
> 
> "It's unclear so far what the reason for that is."
> 
> Adding:
> 
> "See https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html for
> a patch fixing that."
> 
> Ok?

Yes, thanks. I figured the fix for elfutils out after I submitted the perf 
patch.

> Or are you saying that that "unclear" part applies to both libunwind
> and elfutils?

No, libunwind worked fine without these patches for this specific case.

Cheers

-- 
Milian Wolff | milian.wo...@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt, C++ and OpenGL Experts

smime.p7s
Description: S/MIME cryptographic signature


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Arnaldo Carvalho de Melo
Em Mon, Oct 29, 2018 at 04:26:27PM +0100, Milian Wolff escreveu:
> On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> > Libdwfl parses an ELF file itself and creates mappings for the
> > individual sections. Perf on the other hand sees raw mmap events which
> > represent individual sections. When we encounter an address pointing
> > into a mapping with pgoff != 0, we must take that into account and
> > report the file at the non-offset base address.
> > 
> > This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> 
> 
> 
> > Note that the backtrace is still stopping too early, when
> > compared to the nice results obtained via libunwind. It's
> > unclear so far what the reason for that is.
> 
> The remaining issue is due to a bug in elfutils:
> 
> https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html
> 
> With both patches applied, libunwind and elfutils produce the same output for 
> the above scenario.

I'm updating the patch to remove:

"It's unclear so far what the reason for that is."

Adding:

"See https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html for
a patch fixing that."

Ok? Or are you saying that that "unclear" part applies to both libunwind
and elfutils?

- Arnaldo


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Arnaldo Carvalho de Melo
Em Mon, Oct 29, 2018 at 04:26:27PM +0100, Milian Wolff escreveu:
> On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> > Libdwfl parses an ELF file itself and creates mappings for the
> > individual sections. Perf on the other hand sees raw mmap events which
> > represent individual sections. When we encounter an address pointing
> > into a mapping with pgoff != 0, we must take that into account and
> > report the file at the non-offset base address.
> > 
> > This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> 
> 
> 
> > Note that the backtrace is still stopping too early, when
> > compared to the nice results obtained via libunwind. It's
> > unclear so far what the reason for that is.
> 
> The remaining issue is due to a bug in elfutils:
> 
> https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html
> 
> With both patches applied, libunwind and elfutils produce the same output for 
> the above scenario.

I'm updating the patch to remove:

"It's unclear so far what the reason for that is."

Adding:

"See https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html for
a patch fixing that."

Ok? Or are you saying that that "unclear" part applies to both libunwind
and elfutils?

- Arnaldo


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Milian Wolff
On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> Libdwfl parses an ELF file itself and creates mappings for the
> individual sections. Perf on the other hand sees raw mmap events which
> represent individual sections. When we encounter an address pointing
> into a mapping with pgoff != 0, we must take that into account and
> report the file at the non-offset base address.
> 
> This fixes unwinding with libdwfl in some cases. E.g. for a file like:



> Note that the backtrace is still stopping too early, when
> compared to the nice results obtained via libunwind. It's
> unclear so far what the reason for that is.

The remaining issue is due to a bug in elfutils:

https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html

With both patches applied, libunwind and elfutils produce the same output for 
the above scenario.

Cheers
-- 
Milian Wolff | milian.wo...@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt, C++ and OpenGL Experts

smime.p7s
Description: S/MIME cryptographic signature


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Milian Wolff
On Monday, October 29, 2018 3:16:44 PM CET Milian Wolff wrote:
> Libdwfl parses an ELF file itself and creates mappings for the
> individual sections. Perf on the other hand sees raw mmap events which
> represent individual sections. When we encounter an address pointing
> into a mapping with pgoff != 0, we must take that into account and
> report the file at the non-offset base address.
> 
> This fixes unwinding with libdwfl in some cases. E.g. for a file like:



> Note that the backtrace is still stopping too early, when
> compared to the nice results obtained via libunwind. It's
> unclear so far what the reason for that is.

The remaining issue is due to a bug in elfutils:

https://sourceware.org/ml/elfutils-devel/2018-q4/msg00089.html

With both patches applied, libunwind and elfutils produce the same output for 
the above scenario.

Cheers
-- 
Milian Wolff | milian.wo...@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt, C++ and OpenGL Experts

smime.p7s
Description: S/MIME cryptographic signature


Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Jiri Olsa
On Mon, Oct 29, 2018 at 03:16:44PM +0100, Milian Wolff wrote:
> Libdwfl parses an ELF file itself and creates mappings for the
> individual sections. Perf on the other hand sees raw mmap events which
> represent individual sections. When we encounter an address pointing
> into a mapping with pgoff != 0, we must take that into account and
> report the file at the non-offset base address.
> 
> This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> 
> ```
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> 
> using namespace std;
> 
> mutex g_mutex;
> 
> double worker()
> {
> lock_guard guard(g_mutex);
> uniform_real_distribution uniform(-1E5, 1E5);
> default_random_engine engine;
> double s = 0;
> for (int i = 0; i < 1000; ++i) {
> s += norm(complex(uniform(engine), uniform(engine)));
> }
> cout << s << endl;
> return s;
> }
> 
> int main()
> {
> vector> results;
> for (int i = 0; i < 1; ++i) {
> results.push_back(async(launch::async, worker));
> }
> return 0;
> }
> ```
> 
> Compile it with `g++ -g -O2`, then record it with
> `perf record --call-graph dwarf -e sched:sched_switch`.
> 
> When you analyze it with `perf script` and libunwind, you should see:
> 
> ```
> cpp-locking 20038 [005] 54830.236589: sched:sched_switch: 
> prev_comm=cpp-locking prev_pid=20038 prev_prio=120 prev_state=T ==> 
> next_comm=swapper/5 next_pid=0 next_prio=120
> b166fec5 __sched_text_start+0x545 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b166fec5 __sched_text_start+0x545 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1670208 schedule+0x28 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b16737cc rwsem_down_read_failed+0xec 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1665e04 call_rwsem_down_read_failed+0x14 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1672a03 down_read+0x13 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b106bd85 __do_page_fault+0x445 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b18015f5 page_fault+0x45 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> 7f38e4252591 new_heap+0x101 (/usr/lib/libc-2.28.so)
> 7f38e4252d0b arena_get2.part.4+0x2fb (/usr/lib/libc-2.28.so)
> 7f38e4255b1c tcache_init.part.6+0xec (/usr/lib/libc-2.28.so)
> 7f38e42569e5 __GI___libc_malloc+0x115 (inlined)
> 7f38e4241790 __GI__IO_file_doallocate+0x90 (inlined)
> 7f38e424fbbf __GI__IO_doallocbuf+0x4f (inlined)
> 7f38e424ee47 __GI__IO_file_overflow+0x197 (inlined)
> 7f38e424df36 _IO_new_file_xsputn+0x116 (inlined)
> 7f38e4242bfb __GI__IO_fwrite+0xdb (inlined)
> 7f38e463fa6d std::basic_streambuf 
> >::sputn(char const*, long)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits >::_M_put(char const*, long)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits > std::__write(std::ostreambuf_iterator std::char_traits >, char const*, int)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits > std::num_put std::char_traits > 
> >::_M_insert_float(std::ostreambuf_iterator
> 7f38e464bd70 std::num_put std::char_traits > >::put(std::ostreambuf_iterator std::char_traits >, std::ios_base&, char, double) const+0x90 (inl>
> 7f38e464bd70 std::ostream& 
> std::ostream::_M_insert(double)+0x90 (/usr/lib/libstdc++.so.6.0.25)
> 563b9cb502f7 std::ostream::operator<<(double)+0xb7 (inlined)
> 563b9cb502f7 worker()+0xb7 
> (/ssd/milian/projects/kdab/rnd/hotspot/build/tests/test-clients/cpp-locking/cpp-locking)
> 563b9cb506fb double std::__invoke_impl (*)()>(std::__invoke_other, double (*&&)())+0x2b (inlined)
> 563b9cb506fb std::__invoke_result::type 
> std::__invoke(double (*&&)())+0x2b (inlined)
> 563b9cb506fb decltype (__invoke((_S_declval<0ul>)())) 
> std::thread::_Invoker 
> >::_M_invoke<0ul>(std::_Index_tuple<0ul>)+0x2b (inlined)
> 563b9cb506fb std::thread::_Invoker 
> >::operator()()+0x2b (inlined)
> 563b9cb506fb 
> std::__future_base::_Task_setter,
>  std::__future_base::_Result_base::_Deleter>, 
> std::thread::_Invoker >, dou>
> 563b9cb506fb 
> std::_Function_handler std::__future_base::_Result_base::_Deleter> (), 
> std::__future_base::_Task_setter
> 563b9cb507e8 
> std::function std::__future_base::_Result_base::_Deleter> ()>::operator()() const+0x28 
> (inlined)
> 563b9cb507e8 
> std::__future_base::_State_baseV2::_M_do_set(std::function  std::__future_base::_Result_base::_Deleter> ()>*, bool*)+0x28 (/ssd/milian/>
> 7f38e46d24fe __pthread_once_slow+0xbe 
> (/usr/lib/libpthread-2.28.so)
> 563b9cb51149 

Re: [PATCH] perf util: take pgoff into account when reporting elf to libdwfl

2018-10-29 Thread Jiri Olsa
On Mon, Oct 29, 2018 at 03:16:44PM +0100, Milian Wolff wrote:
> Libdwfl parses an ELF file itself and creates mappings for the
> individual sections. Perf on the other hand sees raw mmap events which
> represent individual sections. When we encounter an address pointing
> into a mapping with pgoff != 0, we must take that into account and
> report the file at the non-offset base address.
> 
> This fixes unwinding with libdwfl in some cases. E.g. for a file like:
> 
> ```
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> #include 
> 
> using namespace std;
> 
> mutex g_mutex;
> 
> double worker()
> {
> lock_guard guard(g_mutex);
> uniform_real_distribution uniform(-1E5, 1E5);
> default_random_engine engine;
> double s = 0;
> for (int i = 0; i < 1000; ++i) {
> s += norm(complex(uniform(engine), uniform(engine)));
> }
> cout << s << endl;
> return s;
> }
> 
> int main()
> {
> vector> results;
> for (int i = 0; i < 1; ++i) {
> results.push_back(async(launch::async, worker));
> }
> return 0;
> }
> ```
> 
> Compile it with `g++ -g -O2`, then record it with
> `perf record --call-graph dwarf -e sched:sched_switch`.
> 
> When you analyze it with `perf script` and libunwind, you should see:
> 
> ```
> cpp-locking 20038 [005] 54830.236589: sched:sched_switch: 
> prev_comm=cpp-locking prev_pid=20038 prev_prio=120 prev_state=T ==> 
> next_comm=swapper/5 next_pid=0 next_prio=120
> b166fec5 __sched_text_start+0x545 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b166fec5 __sched_text_start+0x545 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1670208 schedule+0x28 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b16737cc rwsem_down_read_failed+0xec 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1665e04 call_rwsem_down_read_failed+0x14 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b1672a03 down_read+0x13 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b106bd85 __do_page_fault+0x445 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> b18015f5 page_fault+0x45 
> (/lib/modules/4.14.78-1-lts/build/vmlinux)
> 7f38e4252591 new_heap+0x101 (/usr/lib/libc-2.28.so)
> 7f38e4252d0b arena_get2.part.4+0x2fb (/usr/lib/libc-2.28.so)
> 7f38e4255b1c tcache_init.part.6+0xec (/usr/lib/libc-2.28.so)
> 7f38e42569e5 __GI___libc_malloc+0x115 (inlined)
> 7f38e4241790 __GI__IO_file_doallocate+0x90 (inlined)
> 7f38e424fbbf __GI__IO_doallocbuf+0x4f (inlined)
> 7f38e424ee47 __GI__IO_file_overflow+0x197 (inlined)
> 7f38e424df36 _IO_new_file_xsputn+0x116 (inlined)
> 7f38e4242bfb __GI__IO_fwrite+0xdb (inlined)
> 7f38e463fa6d std::basic_streambuf 
> >::sputn(char const*, long)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits >::_M_put(char const*, long)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits > std::__write(std::ostreambuf_iterator std::char_traits >, char const*, int)+0x1cd (inlined)
> 7f38e463fa6d std::ostreambuf_iterator std::char_traits > std::num_put std::char_traits > 
> >::_M_insert_float(std::ostreambuf_iterator
> 7f38e464bd70 std::num_put std::char_traits > >::put(std::ostreambuf_iterator std::char_traits >, std::ios_base&, char, double) const+0x90 (inl>
> 7f38e464bd70 std::ostream& 
> std::ostream::_M_insert(double)+0x90 (/usr/lib/libstdc++.so.6.0.25)
> 563b9cb502f7 std::ostream::operator<<(double)+0xb7 (inlined)
> 563b9cb502f7 worker()+0xb7 
> (/ssd/milian/projects/kdab/rnd/hotspot/build/tests/test-clients/cpp-locking/cpp-locking)
> 563b9cb506fb double std::__invoke_impl (*)()>(std::__invoke_other, double (*&&)())+0x2b (inlined)
> 563b9cb506fb std::__invoke_result::type 
> std::__invoke(double (*&&)())+0x2b (inlined)
> 563b9cb506fb decltype (__invoke((_S_declval<0ul>)())) 
> std::thread::_Invoker 
> >::_M_invoke<0ul>(std::_Index_tuple<0ul>)+0x2b (inlined)
> 563b9cb506fb std::thread::_Invoker 
> >::operator()()+0x2b (inlined)
> 563b9cb506fb 
> std::__future_base::_Task_setter,
>  std::__future_base::_Result_base::_Deleter>, 
> std::thread::_Invoker >, dou>
> 563b9cb506fb 
> std::_Function_handler std::__future_base::_Result_base::_Deleter> (), 
> std::__future_base::_Task_setter
> 563b9cb507e8 
> std::function std::__future_base::_Result_base::_Deleter> ()>::operator()() const+0x28 
> (inlined)
> 563b9cb507e8 
> std::__future_base::_State_baseV2::_M_do_set(std::function  std::__future_base::_Result_base::_Deleter> ()>*, bool*)+0x28 (/ssd/milian/>
> 7f38e46d24fe __pthread_once_slow+0xbe 
> (/usr/lib/libpthread-2.28.so)
> 563b9cb51149