This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
Re: return function clarification
- From: Josh Stone <jistone at redhat dot com>
- To: domenico dot dileo at unina dot it
- Cc: "systemtap at sourceware dot org" <systemtap at sourceware dot org>
- Date: Thu, 09 Aug 2012 09:51:21 -0700
- Subject: Re: return function clarification
- References: <20120809123546.96805e6kiwu4uuma@inbox.unina.it>
On 08/09/2012 03:35 AM, domenico.dileo@unina.it wrote:
> Hello,
> I'm trying to understand a bit more on the
> function call sequence.
> I'm just considering the memory manager sub-component
> and understand the function call graph
> at runtime (i.e., when there is a specific process
> running).
>
> I wrote the following stap script
>
> probe kernel.function("*@mm/*.c").call{
> print_invocation("MM", 1)
> }
> probe kernel.function("*@mm/*.c").return{
> print_invocation("MM", -1)
> }
>
> function print_invocation(subsystem, indent){
> if(pid()== target()){
> printf(" %s %s %s %s %p\n",
> subsystem,
> thread_indent(indent),
> (indent>0?"->":"<-"),
> probefunc(), addr())
> }
> }
>
> The output (output1) of the script (when "top" command is running) is
> [LineNumber Subsystem thread_indent probefunc PC_address]
>
> 1 MM 0 top(14861): -> kmem_cache_alloc 0xffffffffc018c880
> 2 MM 1701 top(14861): -> should_failslab 0xffffffffc018bea0
> 3 MM 1799 top(14861): <- should_failslab 0xffffffffc018c8a2
> 4 MM 1839 top(14861): -> kmem_flagcheck 0xffffffffc018a5f0
> 5 MM 1853 top(14861): <- kmem_flagcheck 0xffffffffc018c8bb
>
> Now if I use the addr2line utility with the PC addresses
> on the last column, I get output2
>
> 1 MM -> kmem_cache_alloc /mm/slab.c:3823
> 2 MM -> should_failslab /mm/slab.c:3335
> 3 MM <- __cache_alloc /mm/slab.c:3667
> 4 MM -> kmem_flagcheck /mm/slab.c:2882
> 5 MM <- __cache_alloc /mm/slab.c:3671
>
> I have 2 questions:
> 1) How should I interpret the call sequence in output1?
> I suppose the meaning is Kmem_cache_alloc calls should_fail_slab
> which returns (line 3) and then kmem_cache_alloc calls kmem_check
> which executes and returns and so on... right?
Yes, that's correct.
Note that this is what's happening at the level of machine code. If you
look at the source, kmem_cache_alloc actually calls __cache_alloc first,
which then calls those other functions. But __cache_alloc is inlined,
so we don't see its call/return pair.
It may be interesting to try augmenting your script with an extra probe
kernel.function("*@mm/*.c").inline. But since there's no .return
equivalent for inlines, it's hard to know where that ends. Thus I
wouldn't indent those, since there's no chance to unindent.
> 2) In output2 the name of the function at line 3, 5 and in general
> every time the function returns is different from output1.
> To obtained those names I just used addr2line with the PC_address
> in output1.
> For instance, for the 3rd line of output2 I use
> addr2line -f -e /boot... c018c8a2 which returns __cache_alloc
So two things are happening here. First, the .return probe is activated
just *after* the "ret" instruction, so the addr() you get is actually
for the caller of the function that returned. If you look at the range
of addresses, this makes sense - 18c880, 18c8a2, and 18c8bb are all
close, probably all in kmem_cache_alloc.
The second thing is that addr2line *does* interpret inline information
when it looks up addresses, which is why you get __cache_alloc. I think
if you use addr2line -i, you should see the full chain of inline calls
that led to this address (which may be several levels deep).
Josh