Re: [Libunwind-devel] [PATCH 6/8] Recognise and unwind through PLT.

[Lassi Tuura]

Hi,

Thanks for looking into the patches.

> This patch seems to break a couple of unit tests. Could you please take a 
> look?

Can you be more specific about what you run into, and on what sort of a system?

I did tests before (1) and after (2) applying all the patches from the first 
set. I don't have any test result differences in my --disable-block-signals 
--enable-debug build. I ran the tests on RHEL5.4-based system, 
2.6.18-164.11.1.el5 x86_64 kernel, GLIBC 2.5 (compiled with GCC 4.1.2), GCC 
4.5.0 for user land compilations.

There are some minor differences to how it fails for me, but as far as I can 
tell the root cause always remains the same. Gtest-dyn1 does not describe stack 
movement at 0x403032 (3); I know it copies code around, but other than that I 
am not entirely sure what it is meant to demonstrate. The test-setjmp ends up 
in frame-chain code and gets it wrong, ending up trying to trace ip=0 (4). All 
run-ptrace-misc failures I looked at are caused by missing unwind info, either 
epilogues or just missing and getting things wrong in frame-chain walk (5).

> git apply gave me a few whitespace warnings with some of the patches.

Sorry about that, something about how I mailed it must have mangled white 
space. It was supposed to be an attachment and remain intact, but obviously 
that didn't work.

At any rate, I don't have white space warnings with the patches. I can provide 
the patches some other way if you prefer.

Regards,
Lassi

(1)

make  check-TESTS
make[2]: Entering directory `/afs/cern.ch/user/l/lat/dev/igprof/b/unwind/tests'
PASS: test-proc-info
PASS: test-static-link
PASS: test-strerror
PASS: Gtest-bt
PASS: Ltest-bt
PASS: Gtest-exc
PASS: Ltest-exc
PASS: Gtest-init
PASS: Ltest-init
PASS: Gtest-concurrent
PASS: Ltest-concurrent
PASS: Gtest-resume-sig
PASS: Ltest-resume-sig
FAILURE: expected 13, not 1 frames below signal frame
FAIL: Gtest-dyn1
FAILURE: expected 13, not 1 frames below signal frame
FAIL: Ltest-dyn1
PASS: test-async-sig
PASS: test-flush-cache
PASS: test-init-remote
PASS: test-mem
lt-test-setjmp: ../../../libunwind/src/dwarf/Gparser.c:709: apply_reg_state: 
Assertion `rs->reg[17].where == DWARF_WHERE_EXPR' failed.
/bin/sh: line 4:  2732 Aborted                 ${dir}$tst
FAIL: test-setjmp
PASS: test-ptrace
PASS: Ltest-nomalloc
PASS: rs-race
PASS: run-check-namespace
PASS: run-ptrace-mapper
FAILURE: unw_step() returned -8 for ip=34982094fc (start ip=34982094fc)
unwind failed with ret=-8
FAILURE: detected 2 errors
FAIL: run-ptrace-misc
===========================================
4 of 26 tests failed
Please report to address@hidden
===========================================


(2)

make  check-TESTS
make[2]: Entering directory `/afs/cern.ch/user/l/lat/dev/igprof/b/unwind/tests'
PASS: test-proc-info
PASS: test-static-link
PASS: test-strerror
PASS: Gtest-bt
PASS: Ltest-bt
PASS: Gtest-exc
PASS: Ltest-exc
PASS: Gtest-init
PASS: Ltest-init
PASS: Gtest-concurrent
PASS: Ltest-concurrent
PASS: Gtest-resume-sig
PASS: Ltest-resume-sig
FAILURE: expected 13, not 1 frames below signal frame
FAIL: Gtest-dyn1
FAILURE: expected 13, not 1 frames below signal frame
FAIL: Ltest-dyn1
PASS: test-async-sig
PASS: test-flush-cache
PASS: test-init-remote
PASS: test-mem
lt-test-setjmp: ../../../libunwind/src/dwarf/Gparser.c:743: apply_reg_state: 
Assertion `rs->reg[17].where == DWARF_WHERE_EXPR' failed.
/bin/sh: line 4: 31841 Aborted                 ${dir}$tst
FAIL: test-setjmp
PASS: test-ptrace
PASS: Ltest-nomalloc
PASS: rs-race
PASS: run-check-namespace
PASS: run-ptrace-mapper
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=400636)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=40063b)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=4005c0)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=4005c6)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=3498212890)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=3498208e87)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=34982094fc (start ip=34982094fc)
unwind failed with ret=-8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=349820cd92)
unwind failed with ret=-8
FAILURE: detected 16 errors
FAIL: run-ptrace-misc
===========================================
4 of 26 tests failed
Please report to address@hidden
===========================================

(3)

$ tests/Gtest-dyn1 v
old code @ 0x400ba0, new code @ 0x14a65010
iteration ii
iteration iii
iteration iv
iteration v
iteration vi
iteration vii
iteration viii
iteration ix
iteration x
caught signal 11
ip = 14a6504b <copy_of_template+0x3b>
FAILURE: expected 13, not 1 frames below signal frame

$ gdb --args tests/.libs/Gtest-dyn1 v
GNU gdb (GDB) 7.1
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from 
/afs/cern.ch/user/l/lat/dev/igprof/b/unwind/tests/.libs/Gtest-dyn1...done.
(gdb) r
Starting program: 
/afs/cern.ch/user/l/lat/dev/igprof/b/unwind/tests/.libs/Gtest-dyn1 v
old code @ 0x400b70, new code @ 0x403010
iteration ii
iteration iii
iteration iv
iteration v
iteration vi
iteration vii
iteration viii
iteration ix
iteration x

Program received signal SIGSEGV, Segmentation fault.
0x000000000040304b in ?? ()
(gdb) where
#0  0x000000000040304b in ?? ()
#1  0x0000000000403010 in ?? ()
#2  0x00007fffffffaa40 in ?? ()
#3  0x00007fffffffa9d0 in ?? ()
#4  0x0000000000000001 in ?? ()
#5  0x0000000000000000 in ?? ()

(gdb) disass 0x403010,0x40304b
Dump of assembler code from 0x403010 to 0x40304b:
   0x0000000000403010:  mov    $0xb,%eax
   0x0000000000403015:  mov    %rbx,-0x28(%rsp)
   0x000000000040301a:  mov    %rbp,-0x20(%rsp)
   0x000000000040301f:  sub    %edi,%eax
   0x0000000000403021:  mov    %r12,-0x18(%rsp)
   0x0000000000403026:  mov    %r13,-0x10(%rsp)
   0x000000000040302b:  cltq   
   0x000000000040302d:  mov    %r14,-0x8(%rsp)
   0x0000000000403032:  sub    $0x28,%rsp
   0x0000000000403036:  mov    (%r8,%rax,8),%rax
   0x000000000040303a:  mov    %edi,%ebx
   0x000000000040303c:  mov    %rsi,%r12
   0x000000000040303f:  mov    %rdx,%rbp
   0x0000000000403042:  mov    %rcx,%r13
   0x0000000000403045:  mov    %r8,%r14
   0x0000000000403048:  mov    %rcx,%rdi
End of assembler dump.

(4)

Before patches:

$ UNW_DEBUG_LEVEL=100 tests/test-setjmp |& tail -20                             
                          
                >get_rs_cache: get_rs_cache: acquiring lock
              >_ULx86_64_dwarf_find_proc_info: looking for IP=0x400a18
               >callback: checking , base=0x0)
               >callback: found table `': segbase=0x401790, len=8, gp=0x402b28, 
table_data=0x40179c
 >lookup: e->start_ip_offset = fffff570
 >lookup: e->start_ip_offset = fffff400
 >lookup: e->start_ip_offset = fffff3c0
 >lookup: e->start_ip_offset = fffff350
 >_ULx86_64_dwarf_search_unwind_table: IP 400a18 inside range 400000-402e48, 
 >but no explicit unwind info found
                >put_rs_cache: unmasking signals/interrupts and releasing lock
               >_ULx86_64_dwarf_step: returning -10
             >_ULx86_64_step: dwarf_step() failed (ret=-10), trying frame-chain
                >access_mem: mem[0000000000400a19] -> 4808ec83489090f4
                >access_mem: mem[0000000000400a21] -> 8548000020f9058b
                >access_mem: mem[00007fffb203a8e8] -> 0
  >_ULx86_64_step: returning 0
 >_ULx86_64_step: (cursor=0x7fffb2039d10, ip=0x0000000000000000)
                >get_rs_cache: get_rs_cache: acquiring lock
                >put_rs_cache: unmasking signals/interrupts and releasing lock
lt-test-setjmp: ../../../libunwind/src/dwarf/Gparser.c:709: apply_reg_state: 
Assertion `rs->reg[17].where == DWARF_WHERE_EXPR' failed.

After patches it's the same except there's is_plt_entry call in the "trying 
frame-chain" part.

(5)

Failure before patches:

$ objdump -d /lib64/ld-linux-x86-64.so.2 | grep -B10 34982094fc:
  34982094e0:   48 8b 85 08 ff ff ff    mov    -0xf8(%rbp),%rax
  34982094e7:   48 89 10                mov    %rdx,(%rax)
  34982094ea:   48 8b 45 b8             mov    -0x48(%rbp),%rax
  34982094ee:   48 8d 65 d8             lea    -0x28(%rbp),%rsp
  34982094f2:   5b                      pop    %rbx
  34982094f3:   41 5c                   pop    %r12
  34982094f5:   41 5d                   pop    %r13
  34982094f7:   41 5e                   pop    %r14
  34982094f9:   41 5f                   pop    %r15
  34982094fb:   c9                      leaveq 
  34982094fc:   c3                      retq   

Failures after patches:

$ UNW_DEBUG_LEVEL=5 tests/.libs/test-ptrace -c -t tests/.libs/test-ptrace-misc 
|& grep -B10 FAILURE
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000400639, 
 >cfa=0x00007fff58097020)
 >_Ux86_64_dwarf_search_unwind_table: IP 400638 inside range 400000-402940, but 
 >no explicit unwind info found
  >_Ux86_64_step: returning 0
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: IP 4005fe inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x00000000004005fe, 
 >cfa=0x00007fff58094b18)
 >_Ux86_64_dwarf_search_unwind_table: IP 4005fe inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: [RBP=0x6] = 0x1 (cfa = 0x7fff58094b18)
 >_Ux86_64_step: Frame Chain [RIP=0x9] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=4005fe)
unwind failed with ret=-8
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: IP 400603 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000400603, 
 >cfa=0x00007fff58094b10)
 >_Ux86_64_dwarf_search_unwind_table: IP 400603 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: [RBP=0x6] = 0x1 (cfa = 0x7fff58094b10)
 >_Ux86_64_step: Frame Chain [RIP=0x9] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=400603)
unwind failed with ret=-8
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: IP 400588 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000400588, 
 >cfa=0x00007fff58094b10)
 >_Ux86_64_dwarf_search_unwind_table: IP 400588 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: [RBP=0x6] = 0x1 (cfa = 0x7fff58094b10)
 >_Ux86_64_step: Frame Chain [RIP=0x9] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=400588)
unwind failed with ret=-8
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: IP 40058e inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x000000000040058e, 
 >cfa=0x00007fff58094b08)
 >_Ux86_64_dwarf_search_unwind_table: IP 40058e inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: [RBP=0x6] = 0x1 (cfa = 0x7fff58094b08)
 >_Ux86_64_step: Frame Chain [RIP=0x9] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=40058e)
unwind failed with ret=-8
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = 1358, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821b338
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000003498212890, 
 >cfa=0x00007fff58094b08)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = 1358, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821b338
  >_Ux86_64_step: returning 1
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x00002b7c6962c000, 
 >cfa=0x00007fff58094b10)
 >_Ux86_64_step: [RBP=0x6] = 0x1 (cfa = 0x7fff58094b10)
 >_Ux86_64_step: Frame Chain [RIP=0x9] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=3498212890)
--
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = a50, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821aa30
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000003498208e87, 
 >cfa=0x00007fff580948f0)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = a50, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821aa30
  >_Ux86_64_step: returning 1
 >_Ux86_64_dwarf_search_unwind_table: IP 4003d1 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x00000000004003d2, 
 >cfa=0x00007fff580949a0)
 >_Ux86_64_dwarf_search_unwind_table: IP 4003d1 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: [RBP=0x7fff58094970] = 0x100000000 (cfa = 0x7fff580949a0)
 >_Ux86_64_step: Frame Chain [RIP=0x100000008] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=3498208e87)
--
  >_Ux86_64_step: returning 1
 >_Ux86_64_dwarf_search_unwind_table: IP 400638 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000400639, 
 >cfa=0x00007fff58097020)
 >_Ux86_64_dwarf_search_unwind_table: IP 400638 inside range 400000-402940, but 
 >no explicit unwind info found
  >_Ux86_64_step: returning 0
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = a88, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821aa68
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x00000034982094fc, 
 >cfa=0x00007fff58094a88)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = a88, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821aa68
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=34982094fc (start ip=34982094fc)
--
  >_Ux86_64_step: returning 0
 >_Ux86_64_init_remote: (cursor=0x7fffaf971d90)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = c68, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821ac48
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x000000349820cd92, 
 >cfa=0x00007fff58094ac8)
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = c68, segbase = 
 >3498219fe0, debug_frame_base = 0, fde_addr = 349821ac48
  >_Ux86_64_step: returning 1
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000000003, 
 >cfa=0x00007fff58094b08)
 >_Ux86_64_step: [RBP=0x7fff58094af8] = 0x4 (cfa = 0x7fff58094b08)
 >_Ux86_64_step: Frame Chain [RIP=0xc] = 0xffffffffffffffff
  >_Ux86_64_step: returning -8
FAILURE: unw_step() returned -8 for ip=ffffffffffffffff (start ip=349820cd92)
--
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = 108, segbase = 401408, 
 >debug_frame_base = 0, fde_addr = 401510
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x00000000004012e3, 
 >cfa=0x00007fff58096f50)
  >_Ux86_64_step: returning 1
 >_Ux86_64_dwarf_search_unwind_table: e->fde_offset = 5fdc, segbase = 
 >34987237ec, debug_frame_base = 0, fde_addr = 34987297c8
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x000000349861d994, 
 >cfa=0x00007fff58096f60)
  >_Ux86_64_step: returning 1
 >_Ux86_64_dwarf_search_unwind_table: IP 400638 inside range 400000-402940, but 
 >no explicit unwind info found
 >_Ux86_64_step: (cursor=0x7fffaf971d90, ip=0x0000000000400639, 
 >cfa=0x00007fff58097020)
 >_Ux86_64_dwarf_search_unwind_table: IP 400638 inside range 400000-402940, but 
 >no explicit unwind info found
  >_Ux86_64_step: returning 0
FAILURE: detected 16 errors