Systemtap probe to log the entry/exit of all user functions in a C++ binary is missing some function exits

10 Views Asked by At

I am trying to use this .stp script to get a callgraph (entry and exit timestamps for each function, basically) of a C++ binary:

probe process("/users/rohit/a.out").function("*") {
    printf("[%d] Enter %s\n", gettimeofday_ms(), probefunc())
}

probe process("/users/rohit/a.out").function("*").return {
    printf("[%d] Exit %s\n", gettimeofday_ms(), probefunc())
}

As an initial test, I am trying to get the call-graph for a very simple C++ function:


#include <iostream>

int work_b()
{
    return -1;
}

int work_a(){
    int z = work_b();
    return 1;
}

int main(){
    work_a();
    return 0;
}

I run sudo stap test.stp (the above file) and then run ./a.out. This is the output I see from stap:

[1697046499523] Enter _start
[1697046499523] Enter __libc_csu_init
[1697046499523] Enter _init
[1697046499523] Exit __libc_csu_init
[1697046499523] Enter frame_dummy
[1697046499523] Enter register_tm_clones
[1697046499523] Exit __libc_csu_init
[1697046499523] Exit __libc_csu_init
[1697046499523] Enter _GLOBAL__sub_I__Z6work_bv
[1697046499523] Enter _Z41__static_initialization_and_destruction_0ii
[1697046499523] Exit _GLOBAL__sub_I__Z6work_bv
[1697046499523] Exit __libc_csu_init
[1697046499523] Exit 0x7f50fdae6010
[1697046499523] Enter main
[1697046499523] Enter _Z6work_av
[1697046499523] Enter _Z6work_bv
[1697046499523] Exit _Z6work_av
[1697046499523] Exit main
[1697046499523] Exit 0x7f50fdae6083
[1697046499523] Enter __do_global_dtors_aux
[1697046499523] Enter deregister_tm_clones
[1697046499523] Exit __do_global_dtors_aux
[1697046499523] Exit 0x7f50fdeb2f6b
[1697046499523] Enter _fini
[1697046499523] Exit 0x7f50fdeb2f8d

What I am interested in is everything that happens in main(), so these few lines:

[1697046499523] Enter main
[1697046499523] Enter _Z6work_av
[1697046499523] Enter _Z6work_bv
[1697046499523] Exit _Z6work_av
[1697046499523] Exit main

Question: Why is Exit _Z6work_bv not being captured by the probe function("*").return? I tried modifying test.stp to add an extra probe that just captures the function.return of just this specific function that is being missed:

probe process("/users/rohit/a.out").function("_Z6work_bv").return {
    printf("TEST - is this function even being captured\n")
}

And this is what the new output looks like

[1697046736747] Enter _start
[1697046736747] Enter __libc_csu_init
[1697046736747] Enter _init
[1697046736747] Exit __libc_csu_init
[1697046736747] Enter frame_dummy
[1697046736747] Enter register_tm_clones
[1697046736747] Exit __libc_csu_init
[1697046736747] Exit __libc_csu_init
[1697046736747] Enter _GLOBAL__sub_I__Z6work_bv
[1697046736747] Enter _Z41__static_initialization_and_destruction_0ii
[1697046736747] Exit _GLOBAL__sub_I__Z6work_bv
[1697046736747] Exit __libc_csu_init
[1697046736747] Exit 0x7f144b502010
[1697046736747] Enter main
[1697046736747] Enter _Z6work_av
[1697046736747] Enter _Z6work_bv
[1697046736747] Exit _Z6work_av
TEST - is this function even being captured
[1697046736747] Exit main
[1697046736747] Exit 0x7f144b502083
[1697046736747] Enter __do_global_dtors_aux
[1697046736747] Enter deregister_tm_clones
[1697046736747] Exit __do_global_dtors_aux
[1697046736747] Exit 0x7f144b8cef6b
[1697046736747] Enter _fini
[1697046736747] Exit 0x7f144b8cef8d

Question: Why is probe.function("_Z6work_bv").return able to capture this function, but .function("*") isn't able to? Also, why is work_b() exit being printed after work_a() exit?

0

There are 0 best solutions below