This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
Re: Some questions about kernel stack backtrace when using SystemTap
- From: Mark Wielaard <mjw at redhat dot com>
- To: Nan Xiao <xiaonan830818 at gmail dot com>
- Cc: systemtap at sourceware dot org
- Date: Thu, 12 Nov 2015 11:58:02 +0100
- Subject: Re: Some questions about kernel stack backtrace when using SystemTap
- Authentication-results: sourceware.org; auth=none
- References: <CA+MhoaOwUsf=3RqAhG1igfYZJxEFUGW2WWBqbF8sZU5wfC-tWw at mail dot gmail dot com>
On Thu, 2015-11-12 at 16:01 +0800, Nan Xiao wrote:
> I am trying to print kernel stack backtrace when executing
> "generic_file_open" function.
> And the output confuses me:
>
> # stap -e 'probe kernel.function("generic_file_open") {if (execname()
> == "cat") print_backtrace() print("\n");}'
>
>
> 0xffffffff80152140 : generic_file_open+0x0/0x20 [kernel]
> 0xffffffff800082e9 : dump_trace+0x79/0x1a0 [kernel]
> 0xffffffffa085ab1d [stap_92f96ed1154d2edf7d3c12071ce7fd2f_6907+0x8b1d/0x0]
> 0xffffffffa085ad79 [stap_92f96ed1154d2edf7d3c12071ce7fd2f_6907+0x8d79/0x0]
> 0xffffffff804bca5d : kprobe_ftrace_handler+0xcd/0x120 [kernel]
> 0xffffffff800c7e56 : ftrace_ops_list_func+0xf6/0x110 [kernel]
> 0xffffffff804c1562 : ftrace_regs_call+0x5/0x77 [kernel]
> 0xffffffff80152140 : generic_file_open+0x0/0x20 [kernel] (inexact)
> 0xffffffff80152140 : generic_file_open+0x0/0x20 [kernel] (inexact)
> 0xffffffff80152145 : generic_file_open+0x5/0x20 [kernel] (inexact)
> 0xffffffff80152423 : do_dentry_open+0x143/0x2a0 [kernel] (inexact)
> 0xffffffff8015f509 : __inode_permission+0x59/0xb0 [kernel] (inexact)
> 0xffffffff801634db : do_last+0x21b/0x1290 [kernel] (inexact)
> 0xffffffff8014599a : kmem_cache_alloc_trace+0x1ea/0x470 [kernel] (inexact)
> 0xffffffff8016460b : path_openat+0xbb/0x640 [kernel] (inexact)
> 0xffffffff80165aba : do_filp_open+0x3a/0x90 [kernel] (inexact)
> 0xffffffff80172767 : __alloc_fd+0x87/0x140 [kernel] (inexact)
> 0xffffffff80153b29 : do_sys_open+0x129/0x220 [kernel] (inexact)
> 0xffffffff804c1777 : system_call_fastpath+0x16/0x1b [kernel] (inexact)
>
> My questions are as follow:
>
> (1) What is "(inexact)" meaning?
It means the systemtap unwinder had to guess because it couldn't find
proper unwind information. In this case it seems ftrace_regs_call might
be missing DWARF CFI. So it falls back to guessing the return addresses
on the stack. Looking at the rest of the backtrace it seems it is
guessing somewhat correctly (the three nested generic_file_open calls
look somewhat suspicious, but the rest looks ok). So it is just a
warning that it might not be completely correct since the CFI couldn't
be found at some point.
> (2) I find some stack frames like this:
> 0xffffffffa085ab1d [stap_92f96ed1154d2edf7d3c12071ce7fd2f_6907+0x8b1d/0x0]
> 0xffffffffa085ad79 [stap_92f96ed1154d2edf7d3c12071ce7fd2f_6907+0x8d79/0x0]
> Why aren't they human understandable function names?
Probably because they weren't found. Although I don't know why not.
These are frames in the stap module generated by the script itself.
This backtrace is kind of funny because it happens because the stap
script intercepts a call to generic_file_open which is caused by
dump_trace, which is a kernel function the stap module uses when it
cannot unwind exactly as fallback mechanism. I am not sure why
dump_trace would call generic_file_open though.
Cheers,
Mark