使用-finstrument进行函数调用追踪

假设有个场景,希望在程序在执行的时候,调用函数的时候可以自动打印出它的调用栈。或者说希望自动打印出在这个函数中的执行时间。比如这段程序,希望执行到任何函数的时候,都打印出它的调用堆栈。

#include  <stdio.h>

void foo4() {
    printf("foo()\n");
}

void foo3() {
    foo4();
}

void foo2() {
    foo3();
}

void foo1() {
    foo2();
}

int main() {
    foo1();
    return 0;
}
➜  test_test ./a.out                                             
 {  // trace begin 
   ===> 0x40125c : ./a.out(__cyg_profile_func_enter+0x38) [0x40125c]
   ===> 0x4013e2 : ./a.out(main+0x1a) [0x4013e2]
   ===> 0x7ffff7a356a3 : /lib64/libc.so.6(__libc_start_main+0xf3) [0x7ffff7a356a3]
   ===> 0x4010ae : ./a.out(_start+0x2e) [0x4010ae]
 }
 {  // trace begin 
   ===> 0x40125c : ./a.out(__cyg_profile_func_enter+0x38) [0x40125c]
   ===> 0x4013aa : ./a.out(foo1+0x15) [0x4013aa]
   ===> 0x4013ec : ./a.out(main+0x24) [0x4013ec]
   ===> 0x7ffff7a356a3 : /lib64/libc.so.6(__libc_start_main+0xf3) [0x7ffff7a356a3]
   ===> 0x4010ae : ./a.out(_start+0x2e) [0x4010ae]
 }
 {  // trace begin 
   ===> 0x40125c : ./a.out(__cyg_profile_func_enter+0x38) [0x40125c]
   ===> 0x401377 : ./a.out(foo2+0x15) [0x401377]
   ===> 0x4013b4 : ./a.out(foo1+0x1f) [0x4013b4]
   ===> 0x4013ec : ./a.out(main+0x24) [0x4013ec]
   ===> 0x7ffff7a356a3 : /lib64/libc.so.6(__libc_start_main+0xf3) [0x7ffff7a356a3]
   ===> 0x4010ae : ./a.out(_start+0x2e) [0x4010ae]
 }
 {  // trace begin 
   ===> 0x40125c : ./a.out(__cyg_profile_func_enter+0x38) [0x40125c]
   ===> 0x401344 : ./a.out(foo3+0x15) [0x401344]
   ===> 0x401381 : ./a.out(foo2+0x1f) [0x401381]
   ===> 0x4013b4 : ./a.out(foo1+0x1f) [0x4013b4]
   ===> 0x4013ec : ./a.out(main+0x24) [0x4013ec]
   ===> 0x7ffff7a356a3 : /lib64/libc.so.6(__libc_start_main+0xf3) [0x7ffff7a356a3]
   ===> 0x4010ae : ./a.out(_start+0x2e) [0x4010ae]
 }
 {  // trace begin 
   ===> 0x40125c : ./a.out(__cyg_profile_func_enter+0x38) [0x40125c]
   ===> 0x401311 : ./a.out(foo4+0x15) [0x401311]
   ===> 0x40134e : ./a.out(foo3+0x1f) [0x40134e]
   ===> 0x401381 : ./a.out(foo2+0x1f) [0x401381]
   ===> 0x4013b4 : ./a.out(foo1+0x1f) [0x4013b4]
   ===> 0x4013ec : ./a.out(main+0x24) [0x4013ec]
   ===> 0x7ffff7a356a3 : /lib64/libc.so.6(__libc_start_main+0xf3) [0x7ffff7a356a3]
   ===> 0x4010ae : ./a.out(_start+0x2e) [0x4010ae]
 }
foo()

那要如何实现呢?

最简单的方式是在每个函数里面都插入一个打印堆栈的逻辑,但是会非常麻烦。发现gcc有个特性,可以巧妙的做到这一点。利用__attribute__可以用来设置 Function-Attributes函数属性。在gcc编译的时候加上:-finstrument-functions编译选项就会在每一个用户自定义函数中添加下面两个函数调用:

void __cyg_profile_func_enter(void *this, void *callsite);
void __cyg_profile_func_exit(void *this, void *callsite);

// 这两个函数我们用户可以自己实现
// 其中`this`指针指向当前函数的地址,`callsite`是指向上一级调用函数的地址

修改下代码,实现下这个函数。

#include <stdio.h>
#include <malloc.h>
#include <execinfo.h>
#include <execinfo.h>

void __cyg_profile_func_exit(void* callee, void* callsite) __attribute__((no_instrument_function));
void __cyg_profile_func_enter(void* callee, void* callsite) __attribute__((no_instrument_function));

void __cyg_profile_func_enter(void* callee, void* callsite) {
    void    *funptr = callee;
    char **p = backtrace_symbols(&funptr, 1);
    printf("Entering: %s\n", *p);
    free(p);
}

void __cyg_profile_func_exit(void* callee, void* callsite) {
    void    *funptr = callee;
    char **p = backtrace_symbols(&funptr, 1);
    printf("Exiting: %s\n", *p);
    free(p);
}

void foo4() {
    printf("foo()\n");
}

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

// gcc trace_func.c -rdynamic -finstrument-functions 
./a.out 
Entering: ./a.out(main+0) [0x401233]
Entering: ./a.out(foo4+0) [0x401200]
foo()
Exiting: ./a.out(foo4+0) [0x401200]
Exiting: ./a.out(main+0) [0x401233]

查看下编译后的汇编代码,foo函数中已经被插入了两个函数,分别是__cyg_profile_func_enter和__cyg_profile_func_exit。也就是说,编译器已经在编译的时候,替我们生成了插桩代码了。



如果编译器使用的是g++,直接用g++编译会报错。当然,也可以稍微改动下,这样就可以使用g++编译了。

extern "C" __attribute__((no_instrument_function)) 
void __cyg_profile_func_enter(void *callee, void *caller) {
        void    *funptr = callee;
    char **p = backtrace_symbols(&funptr, 1);
    printf("Entering: %s\n", *p);
    free(p);
}

extern "C" __attribute__((no_instrument_function)) 
void __cyg_profile_func_exit(void *callee, void *caller) {
    void    *funptr = callee;
    char **p = backtrace_symbols(&funptr, 1);
    printf("Exiting: %s\n", *p);
    free(p);
}
// g++ trace_func.c -o test -rdynamic -finstrument-functions 

不过,恰好我的编译器版本比较低,网上搜了一下,在g++版本较低的机器上就刚才的操作就搞不定了。于是,尝试把这个文件用gcc单独编译成一个so。其他的代码用g++编译,程序执行的时候,preload这个so库。这个代码验证下思路:

__attribute__((no_instrument_function))
void __cyg_profile_func_enter(void *this_fn, void *call_site) {
    printf("enter func => %p\n", this_fn);
}

__attribute__((no_instrument_function))
void __cyg_profile_func_exit(void *this_fn, void *call_site) {
    printf("exit func <= %p\n", this_fn);
}
.PHONY: all clean

APP_CFILE=$(wildcard *.c)

FUNC_TRACE_LIB_SO=libfunc_trace.so

all: $(FUNC_TRACE_LIB_SO)

$(FUNC_TRACE_LIB_SO) : $(APP_CFILE)
    gcc -fPIC -shared -o $(FUNC_TRACE_LIB_SO) func_trace.c

clean:
    @$(RM) *.o $(FUNC_TRACE_LIB_SO);

在其他程序需要使用的时候,就可以实现这个功能了。

 LD_PRELOAD=libfunc_trace.so ./a.out

小结:
gcc 提供了一个编译选项,-finstrument-function,编译器在编译代码的时候,可以给用户自定义的函数中插入两个函数,分别在他们进入和离开的时候进行调用。利用这个机制,可以实现很多功能。比如打印函数的调用栈或者统计函数的执行时间等。

不过,这个也可能会带来写性能问题,毕竟没发生一次函数调用都会带来一次额外的开销。需要在评估下在合理使用。

附上一个统计函数执行时间的例子

unsigned int _time_begin = 0;
unsigned int _time_end   = 0;

#define rdtsc(val) do {\
          unsigned int __a,__d; \
          __asm__ __volatile__("rdtsc" : "=a" (__a), "=d" (__d)); \
          (val) = (((unsigned long long)__d)<<32) | (__a); \
        } while(0)

__attribute__((no_instrument_function))
void __cyg_profile_func_enter(void *this_fn, void *call_site) {
    rdtsc(_time_begin);
}

__attribute__((no_instrument_function))
void __cyg_profile_func_exit(void *this_fn, void *call_site) {
    void    *funptr = call_site;
    char **p = backtrace_symbols(&funptr, 1);

    rdtsc(_time_end);
    unsigned int cost = _time_end - _time_begin;
    printf("exec func %s cost %d\n", *p, cost);
    free(p);
}

Google搞的类似的工具 :

[https://llvm.org/docs/XRayExample.html] (XRay轻量级的 C/C++ 函数调用跟踪系统)
https://zhuanlan.zhihu.com/p/565749318

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 158,736评论 4 362
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,167评论 1 291
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,442评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,902评论 0 204
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,302评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,573评论 1 216
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,847评论 2 312
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,562评论 0 197
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,260评论 1 241
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,531评论 2 245
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,021评论 1 258
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,367评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,016评论 3 235
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,068评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,827评论 0 194
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,610评论 2 274
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,514评论 2 269

推荐阅读更多精彩内容