printing kernel backtrace

printing kernel backtrace

[Nikolay Borisov]

Hello,

I've started experimenting with systemtamp and I'd like to print the
callstack leading to the probed function. To that effect I have created
the following very simple tapset:

probe module("dm_thin_pool").function("do_waker") {
    print_syms(callers(-1))
    printf("finished backtrace\n");
}

However the output I get is something like that:

 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffff810a5025 : 0xffffffff810a5025
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
 0xffffffffa0152c8 : 0xffffffffa0152c8
finished backtrace


It seems that systemtap is unable to unwind the debug information? I
believe I have compiled systemtap with the necessary unwidn libraries
but how do I check that for sure?

Re: printing kernel backtrace

[Frank Ch. Eigler]

Hi -


n.borisov wrote:

> I've started experimenting with systemtamp and I'd like to print the
> callstack leading to the probed function. 

Welcome!

> To that effect I have created the following very simple tapset:

(Just a terminology nit: a "tapset" is a set of script fragments for
automated reuse, kind of like libc.  Yours is simply a script.)

> probe module("dm_thin_pool").function("do_waker") {
>     print_syms(callers(-1))
>     printf("finished backtrace\n");
> }

print_backtrace()  would have been equivalent.


> However the output I get is something like that:
>
>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>  0xffffffff810a5025 : 0xffffffff810a5025
>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>  [...]
>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>  0xffffffffa0152c8 : 0xffffffffa0152c8
> finished backtrace

That doesn't look quite right, does it.  I'd expect stap to produce
some messages about missing unwind/symbol information, but it's not
happening right this time.

The problem is probably that the unwind/symbol info for only your
module was included.  Try running your script again, but add

   -d kernel

to the stap command line.


- FChE

Re: printing kernel backtrace

[Nikolay Borisov]

On Sat, Dec 12, 2015 at 4:38 PM, Frank Ch. Eigler <fche@redhat.com> wrote:
>
> Hi -
>
>
> n.borisov wrote:
>
>> I've started experimenting with systemtamp and I'd like to print the
>> callstack leading to the probed function.
>
> Welcome!
>
>> To that effect I have created the following very simple tapset:
>
> (Just a terminology nit: a "tapset" is a set of script fragments for
> automated reuse, kind of like libc.  Yours is simply a script.)
>
>> probe module("dm_thin_pool").function("do_waker") {
>>     print_syms(callers(-1))
>>     printf("finished backtrace\n");
>> }
>
> print_backtrace()  would have been equivalent.
>
>
>> However the output I get is something like that:
>>
>>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>>  0xffffffff810a5025 : 0xffffffff810a5025
>>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>>  [...]
>>  0xffffffffa0152c80 : do_waker+0x0/0x40 [dm_thin_pool]
>>  0xffffffffa0152c8 : 0xffffffffa0152c8
>> finished backtrace
>
> That doesn't look quite right, does it.  I'd expect stap to produce
> some messages about missing unwind/symbol information, but it's not
> happening right this time.
>
> The problem is probably that the unwind/symbol info for only your
> module was included.  Try running your script again, but add
>
>    -d kernel

So using -d kernel does indeed fix the backtrace. For the sake of completeness I
also tried using --ldd which according to the help should include debug info for
all referenced objects (including the kernel) but it doesn't work.
What am I missing?

>
> to the stap command line.
>
>
> - FChE

Re: printing kernel backtrace

[Frank Ch. Eigler]

Hi -

> [...]
> So using -d kernel does indeed fix the backtrace. 

Good; will see if can add some diagnostics.

> For the sake of completeness I also tried using --ldd which
> according to the help should include debug info for all referenced
> objects (including the kernel) but it doesn't work.

A documentation glitch: --ldd is for shared library dependencies,
so not including the kernel, will fix.

- FChE