Re: How to track the functions in self-written module using SystemTap?

[Martin Cermak <mcermak at redhat dot com>]

On  Fri  2016-10-07  12:59 , David Smith wrote:
> On 10/06/2016 05:05 PM, Martin Cermak wrote:
> > On  Mon  2015-12-07  13:53 , David Smith wrote:
> >> 1) Make sure your kernel was compiled with frame pointer support (which
> >> it should if it is a standard RHEL kernel):
> >>
> >> # fgrep FRAME_POINTER /boot/config-`uname -r`
> >> CONFIG_SCHED_OMIT_FRAME_POINTER=y
> >> CONFIG_ARCH_WANT_FRAME_POINTERS=y
> >> CONFIG_FRAME_POINTER=y
> >>
> >> 2) Let's make sure your module still has debuginfo present. First, run
> >> "file" on your module, making sure it says "not stripped". Then go a bit
> >> deeper and run "readelf --sections" on your module - there should be
> >> several sections that start with '.debug', including one called
> >> '.debug_frame'.
> > 
> > I'm traying to trace my own stap module too.  I'm using stap -B
> > CONFIG_DEBUG_INFO=y to put the dfebuginfo into the module.
> > However, this way I seem to get the '.debug_frame' section on
> > RHEL6, but not on RHEL7 or recent Fedora.  Because of this I'm
> > failing to get reasonable backtraces.  Any workaround?
> 
> We actually test this in the systemtap.context/context.exp test case. It
> builds 2 external modules and tries to get backtraces from them (among
> other things). On RHEL7.2 ppc64, the backtrace tests don't pass, but I
> think that's really a test case problem.
> 
> ====
> backtrace from
> module("systemtap_test_module2").function("yyy_func2@/root/rhel7-2.ppc64/testsuite/artifacts/systemtap.context/context/staptestMS19Tt/systemtap_test_module2.c:33"):
>  0xd000000006fd00a0 : yyy_func2+0x0/0x30 [systemtap_test_module2]
>  0xd000000006fd00e0 : yyy_func1+0x10/0x0 [systemtap_test_module2]
>  0xd0000000082c01b8 : stm_write_cmd+0x1b8/0x200 [systemtap_test_module1]
>  0x0 (inexact)
> ====
> 
> The test case expects the '0x0 (inexact)' line to be from the kernel.
> This might be a ppc64-specific problem. But, the backtrace from the
> modules themselves look fine.
> 
> Does your systemtap.context/context.exp test case output look similar?
> 


Yup, it does look similar.  My scenario is slightly different,
but ITSM that looking at context.exp helped me to narrow my
problem down to the GCC invocation.

My scenario is to trace a real stap module.  OTOH, context.exp
traces a module not created by stap.  Here is my scenario:

=======
$ # compile and run the tracee module
$
$ stap -v -m blah -B CONFIG_DEBUG_INFO=y --poison-cache -e 'global x probe timer.s(1) {x<<<1 println(@count(x))}'
$
$ # now run the tracer module (in another terminal):
$
$ stap  -d kernel -e 'probe
module("/home/mcermak/blah.ko").function("_stp_stat_add")
{print_backtrace() exit()}'
WARNING: no or bad debug frame hdr
WARNING: No binary search table for eh frame, doing slow linear
search for /home/mcermak/blah.ko
 0xffffffffc086d628 : probe_2815+0x58/0x4d0 [blah]
$
=======

I'd expect richer backtrace above.  Comparing the simple Makefile
used by context.exp to a relatively complex Makefile of a real
stap module made me think that by commenting out some of the
EXTRA_CFLAGS defined in buildrun.cxx must fix my problem.  And
indeed, following update seems to help:

=======
   // Generate eh_frame for self-backtracing
-  o << "EXTRA_CFLAGS += -fasynchronous-unwind-tables" << endl;
+  //o << "EXTRA_CFLAGS += -fasynchronous-unwind-tables" << endl;
=======

After applying it, and running whole the test again, I'm getting
following output:

=======
$ stap  -d kernel -e 'probe module("/home/mcermak/blah.ko").function("_stp_stat_add") {print_backtrace() exit()}'
 0xffffffffc086d628 : probe_2815+0x58/0x4d0 [blah]
 0xffffffffc086c3c3 : _stp_hrtimer_notify_function+0x223/0x3f0 [blah]
 0xffffffff81115d0e : __hrtimer_run_queues+0xee/0x270 [kernel]
 0xffffffff811164aa : hrtimer_interrupt+0x9a/0x180 [kernel]
 0xffffffff81053588 : local_apic_timer_interrupt+0x38/0x60 [kernel]
 0xffffffff817e011d : smp_apic_timer_interrupt+0x3d/0x50 [kernel]
 0xffffffff817de25c : apic_timer_interrupt+0x8c/0xa0 [kernel]
$
=======

So, when the stap module gets compiled with gcc-6.2.1-1.fc26.x86_64 with
-fasynchronous-unwind-tables, there is no '.debug_frame' section and no
traceback.  Removing this option helps me:

=======
$ readelf --sections blah.ko | grep '.debug_frame'
  [37] .debug_frame      PROGBITS         0000000000000000  00031620
  [38] .rela.debug_frame RELA             0000000000000000  0009a5b0
$
=======

... but probably breaks something else, since the relevant
comment reads: "Generate eh_frame for self-backtracing".


Martin