[Bug runtime/17469] support kernel unwinding based on .eh_frame rather than .debug_frame data

["wcohen at redhat dot com" <sourceware-bugzilla at sourceware dot org>]

https://sourceware.org/bugzilla/show_bug.cgi?id=17469

--- Comment #3 from William Cohen <wcohen at redhat dot com> ---
Can replicate the issue with the backtrace.stp test.  On x86 get a reasonable
backtrace:

$ uname -a
Linux santana 4.1.6-200.fc22.x86_64 #1 SMP Mon Aug 17 19:54:31 UTC 2015 x86_64
x86_64 x86_64 GNU/Linux
$ ../install/bin/stap --all-modules -k -mx
testsuite/systemtap.base/backtrace.stp 
WARNING: no or bad debug frame hdr
WARNING: No binary search table for eh frame, doing slow linear search for x
WARNING: DWARF expression stack underflow in CFI
begin
 0xffffffffa09dd777 [x+0x7777/0x0]
 0xffffffffa09deb7f [x+0x8b7f/0x0]
 0xffffffffa09df143 [x+0x9143/0x0]
 0xffffffffa09dff20 [x+0x9f20/0x0]
 0xffffffffa09e1e31 [x+0xbe31/0x0]
 0xffffffff8122a667 : __vfs_write+0x37/0x110 [kernel]
 0xffffffff8122b086 : vfs_write+0xa6/0x1c0 [kernel]
 0xffffffff8122bdf9 : sys_write+0x59/0xd0 [kernel]
 0xffffffff817a1f2e : system_call_fastpath+0x12/0x71 [kernel]
timer.ms(100)
 0xffffffffa09dd777 [x+0x7777/0x0]
 0xffffffffa09deb7f [x+0x8b7f/0x0]
 0xffffffffa09def26 [x+0x8f26/0x0]
 0xffffffffa09dfba4 [x+0x9ba4/0x0]
 0xffffffff8110c174 : __run_hrtimer+0x74/0x1d0 [kernel]
 0xffffffff8110c673 : hrtimer_interrupt+0x103/0x230 [kernel]
 0xffffffff8105193c : local_apic_timer_interrupt+0x3c/0x70 [kernel]
 0xffffffff817a4d71 : smp_apic_timer_interrupt+0x41/0x60 [kernel]
 0xffffffff817a2dfe : apic_timer_interrupt+0x6e/0x80 [kernel]
end
 0xffffffffa09dd777 [x+0x7777/0x0]
 0xffffffffa09deb7f [x+0x8b7f/0x0]
 0xffffffffa09df143 [x+0x9143/0x0]
 0xffffffffa09dff20 [x+0x9f20/0x0]
 0xffffffffa09e0875 [x+0xa875/0x0]
 0xffffffffa09e185a [x+0xb85a/0x0]
 0xffffffff8122a667 : __vfs_write+0x37/0x110 [kernel]
 0xffffffff8122b086 : vfs_write+0xa6/0x1c0 [kernel]
 0xffffffff8122bdf9 : sys_write+0x59/0xd0 [kernel]
 0xffffffff817a1f2e : system_call_fastpath+0x12/0x71 [kernel]
Keeping temporary directory "/tmp/stapMgFcbq"


On aarch64 which uses the eh_frames get:

# uname -a
Linux amd-seattle-07.khw.lab.eng.bos.redhat.com 4.2.0-0.rc6.19.el7.aarch64 #1
SMP Wed Aug 26 12:25:03 EDT 2015 aarch64 aarch64 aarch64 GNU/Linux
# ../install/bin/stap --all-modules -k -mx
testsuite/systemtap.base/backtrace.stp 
WARNING: no or bad debug frame hdr
WARNING: No binary search table for eh frame, doing slow linear search for x
WARNING: No binary search table for eh frame, doing slow linear search for
/usr/lib/debug/usr/lib/modules/4.2.0-0.rc6.19.el7.aarch64/vmlinux
begin
 0xfffffdfffd428050 [x+0x8050/0x0]
 0xfffffdfffd428068 [x+0x8068/0x0]
 0xfffffdfffd42855c [x+0x855c/0x0]
 0xfffffdfffd429118 [x+0x9118/0x0]
 0xfffffdfffd4297f8 [x+0x97f8/0x0]
 0xfffffdfffd42b050 [x+0xb050/0x0]
 0xfffffe000021c9c4 : __vfs_write+0x48/0x130 [kernel]
 0x0 (inexact)
timer.ms(100)
 0xfffffdfffd428050 [x+0x8050/0x0]
 0xfffffdfffd428068 [x+0x8068/0x0]
 0xfffffdfffd428308 [x+0x8308/0x0]
 0xfffffdfffd428e48 [x+0x8e48/0x0]
 0xfffffe0000122924 : __hrtimer_run_queues+0x148/0x260 [kernel]
 0x0 (inexact)
end
 0xfffffdfffd428050 [x+0x8050/0x0]
 0xfffffdfffd428068 [x+0x8068/0x0]
 0xfffffdfffd42855c [x+0x855c/0x0]
 0xfffffdfffd429118 [x+0x9118/0x0]
 0xfffffdfffd42a1d8 [x+0xa1d8/0x0]
 0xfffffdfffd42afe4 [x+0xafe4/0x0]
 0xfffffe000021c9c4 : __vfs_write+0x48/0x130 [kernel]
 0x0 (inexact)
Keeping temporary directory "/tmp/stapG3PYFa"

The unwinder makes is way out of the systemtap module ("x") and to a
the various functions, but is unable to unwind past that point.  To
get more detail on what is going on with the aarch64 ran the following
and the output is attached:

../install/bin/stap -DDEBUG_UNWIND --all-modules -k -mx
testsuite/systemtap.base/backtrace.stp >& results

The output on aarch64 ends up being huge, 5912226 (almost 6MB).  The
x86 version is merely large 258110 (260KB)

Around the output for the first __vfs_write on aarch64 have:

unwind_frame:1310: cfa reg=29, off=60
unwind_frame:1315: cfa=fffffe001e51fda0 startLoc=fffffe001e51fd40,
endLoc=fffffe001e51fda0
unwind_frame:1322: cie=fffffdffff1824e8 fde=fffffdffff183b78
unwind_frame:1436: set register 19 to fffffe0358918000
unwind_frame:1436: set register 20 to c
unwind_frame:1436: set register 21 to fffffe001e51fec8
unwind_frame:1436: set register 22 to 3fff40702f8
unwind_frame:1436: set register 23 to 80000000
unwind_frame:1436: set register 24 to 15
unwind_frame:1436: set register 25 to 11a
unwind_frame:1436: set register 26 to 40
unwind_frame:1436: set register 27 to fffffe0000772000
unwind_frame:1436: set register 28 to fffffe001e51c000
unwind_frame:1436: set register 29 to fffffe001e51fda0
unwind_frame:1436: set register 30 to fffffe000021c9c4
unwind_frame:1446: returning 0 (fffffe000021c9c4)
_stp_stack_unwind_one_kernel:318: ret=0 PC=fffffe000021c9c4 SP=fffffe001e51fda0
 0xfffffe000021c9c4 : __vfs_write+0x48/0x130 [kernel]
_stp_stack_unwind_one_kernel:300: CONTINUING kernel unwind to depth 7
unwind:1478: pc=fffffe000021c9c3, fffffe000021c9c4
unwind:1518: trying debug_frame
unwind_frame:1178: Module
/usr/lib/debug/usr/lib/modules/4.2.0-0.rc6.19.el7.aarch64/vmlinux: no unwind
frame data
unwind:1522: debug_frame failed: -5, trying eh_frame
unwind_frame:1194:
/usr/lib/debug/usr/lib/modules/4.2.0-0.rc6.19.el7.aarch64/vmlinux: fde=0
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
parse_fde_cie:156: map retAddrReg value 30 to reg_info idx 30
...

Then spews the parse_fde_cie lines thousands of times. the "unwind_frame:1194"
"fde=0" looks wrong.  Did a dump of the eh_frame with:

eu-readelf -w .eh_frame
/usr/lib/debug/lib/modules/4.2.0-0.rc6.19.el7.aarch64/vmlinux >
vmlinux.eh_frame

There is information available but systemtap is not finding it for __vfs_write:

 [ 64b10] FDE length=60 cie=[     0]
   CIE_pointer:              412436
   initial_location:         0xfffffe000021c97c <__vfs_write> (offset:
0x1ac97c)
   address_range:            0x130 (end offset: 0x1acaac)

   Program:
     advance_loc 1 to 0x1ac980
     def_cfa_offset 144
     offset r29 (x29) at cfa-144
     offset r30 (x30) at cfa-136
     advance_loc 1 to 0x1ac984
     def_cfa_register r29 (x29)
     advance_loc 2 to 0x1ac98c
     offset r19 (x19) at cfa-128
     offset r20 (x20) at cfa-120
     offset r21 (x21) at cfa-112
     offset r22 (x22) at cfa-104
     advance_loc 17 to 0x1ac9d0
     remember_state
     restore r30 (x30)
     restore r29 (x29)
     restore r22 (x22)
     restore r21 (x21)
     restore r20 (x20)
     restore r19 (x19)
     def_cfa r31 (sp) at offset 0
     advance_loc 1 to 0x1ac9d4
     restore_state
     advance_loc 39 to 0x1aca70
     remember_state
     restore r19 (x19)
     restore r20 (x20)
     restore r21 (x21)
     restore r22 (x22)
     restore r29 (x29)
     restore r30 (x30)
     def_cfa r31 (sp) at offset 0
     advance_loc 1 to 0x1aca74
     restore_state
     nop

-- 
You are receiving this mail because:
You are the assignee for the bug.