开始之前

很多语言的log模块都有一个功能,就是在打log的时候能够追溯调用栈,有的时候对查bug能有点帮助。之前我也想过给我们的log模块加上C++的backtrace的功能,迟迟一直没有做主要是两个原因:一是C++的backtrace在各个平台和编译器上都不太一样,比较冗杂;二是C/C++在编译优化之后,调用行之类的信息和甚至一些函数可能就被优化没了。所以能提供的信息就相当有限。前两天刚好有朋友问有没有提供这个,所以就花了点时间整理了下适配方案。

思路和方案

具体到方案上,不同编译器、不同的平台都有自己的规则,但是也有少数的事实标准。所以还是可以笼统地分几个主流平台处理这个backtrace。我参考了一些gcc文档、boost代码和其他流传的一些库和方法,总结起来有几种方案。有些方法能提取去模块名称(函数在哪个动态库和或哪个二进制之类),但是有些不能。所以为了简化并且统一,我就没输出模块名。另外为了方便对比,我先贴一下测试的函数:

// 普通函数
void func1(int times) {
    if (times > 0) {
        func1(times - 1);
        return;
    }

    print_trace();
}

// 成员函数
class functor2 {
public:
    void func2(int times) {
        if (times & 0x01) {
            func2(times - 1);
        } else {
            func1(times - 1);
        }
    }
};

// 静态成员
class functor3 {
public:
    static void func3(int times) {
        if (times & 0x01) {
            func3(times - 1);
        } else {
            functor2 f;
            f.func2(times - 1);
        }
    }
};

// 操作符
struct functor4 {
    void operator()(int times) {
        if (times & 0x01) {
            (*this)(times - 1);
        } else {
            functor3::func3(times - 1);
        }
    }
};

// 本地函数
static void func5(int times) {
    if (times & 0x01) {
        func5(times - 1);
    } else {
        functor4 f;
        f(times - 1);
    }
}
// 还是普通函数
void func6(int times) {
    if (times & 0x01) {
        func6(times - 1);
    } else {
        func5(times - 1);
    }
}

Linux/Unix like环境

backtrace方案

libunwind

最简单的一种方式是使用libunwind。他已经给你封装好了接口,比较简单。基本流程就是unw_getcontext->unw_init_local->枚举每一帧unw_get_proc_name+unw_get_proc_info。简化一下代码大概这样:

unw_context_t unw_ctx;
unw_cursor_t unw_cur;
unw_proc_info_t unw_proc;
unw_getcontext(&unw_ctx);
unw_init_local(&unw_cur, &unw_ctx);

char func_name_cache[4096];
unw_word_t unw_offset;
int frame_id = 0;
do {
    // 提取函数符号名到func_name_cache
    unw_get_proc_name(&unw_cur, func_name_cache, sizeof(func_name_cache), &unw_offset);
    // 提取函数信息到unw_proc,unw_proc.start_ip就是函数起始地址
    unw_get_proc_info(&unw_cur, &unw_proc);

    int next_res = unw_step(&unw_cur);

    if (next_res <= 0) {
        puts("All frames.");
    }
    ++ frame_id;
} while(true);

execinfo.h和backtrace

第二种是使用gcc/clang自带的execinfo.h和backtrace功能。代码如下:

void *array[BACKTRACE_MAX_FRAME_NUMBER];
size_t size;
char **func_name_cache;

size = backtrace (array, BACKTRACE_MAX_FRAME_NUMBER);
func_name_cache = backtrace_symbols (array, size);

for (size_t i = 0; i < size; i++) {
    // func_name_cache[i] 里就是模块和函数信息
}

free (func_name_cache);

但是这种方法很多环境里并没有这个头文件和接口,比如MinGW和Android里都没有。所以好事得有fallback的候选方案。

unwind.h和_Unwind_Backtrace

第三种是用POSIX的 unwind.h: _Unwind_Backtrace。这个虽然MinGW里有,但是返回的数据是空的。NDK里也有,但是我没看是否可以用,ndk似乎提供了自己的backtrace函数,我没有去尝试,应该和这个差不多。

这种方法只能提取出函数地址,并不能解析符号。boost.stacktrace也是用了这种方法,它用_Unwind_Backtrace地区出符号以后用了addr2line去做符号转换,写法很暴力。所以我认为这是最后的fallback方案了。

使用_Unwind_Backtrace得先定义回调函数用以填充数据,然后调用_Unwind_Backtrace,代码如下:

#include <unwind.h>

struct print_trace_unwind_state_t {
    size_t frames_to_skip;
    _Unwind_Word* current;
    _Unwind_Word* end;
};

static _Unwind_Reason_Code print_trace_unwind_callback(::_Unwind_Context* context, void* arg) {
    // Note: do not write `::_Unwind_GetIP` because it is a macro on some platforms.
    // Use `_Unwind_GetIP` instead!
    print_trace_unwind_state_t* const state = reinterpret_cast<print_trace_unwind_state_t*>(arg);
    if (state->frames_to_skip) {
        --state->frames_to_skip;
        return _Unwind_GetIP(context) ? ::_URC_NO_REASON : ::_URC_END_OF_STACK;
    }

    *state->current = _Unwind_GetIP(context);

    ++state->current;
    if (!*(state->current - 1) || state->current == state->end) {
        return ::_URC_END_OF_STACK;
    }

    return ::_URC_NO_REASON;
}

void print_trace () {
     _Unwind_Word stacks[BACKTRACE_MAX_FRAME_NUMBER];
    print_trace_unwind_state_t state;
    state.frames_to_skip = 0;
    state.current = stacks;
    state.end = stacks + BACKTRACE_MAX_FRAME_NUMBER;

    ::_Unwind_Backtrace(&print_trace_unwind_callback, &state);
    size_t frames_count = state.current - &stacks[0];
    for (size_t i = 0; i < frames_count; ++ i) {
        // stacks[i] 就是函数地址
    }
}

上述方法理论上在Unix like的系统下都有效。不过我只测过macOS和Linux。

解析符号-demangle

gcc和clang或者libunwind直接解出的符号是原始的符号名称。当然很不好看,所幸的是gcc和clang都提供了内置函数abi::__cxa_demangle来把符号翻译成易懂的版本。这个接口连文档里都是只是提及了一下,我还是看头文件里的注释才知道怎么用的。差评。

前面也提到了boost.stacktrace的做法,它使用了_Unwind_Backtrace来解析函数地址,然后fork进程用addr2line来转换,然后等进程执行完后读取输出,而且还是每个地址fork一个进程跑addr2line。真是暴力又不靠谱,平白无故增加了个进程开销。

接下来可以看看执行结果。

Linux下使用libunwind

g++ -Wall test_backtrace.cpp -O0 -g -ggdb -rdynamic -o test_backtrace.exe -DUSING_LIBUNWIND -lunwind -lunwind-x86_64
clang++ -Wall test_backtrace.cpp -O0 -g -ggdb -rdynamic -o test_backtrace.exe -DUSING_LIBUNWIND -lunwind -lunwind-x86_64

命令和输出:

./test_backtrace.exe

Frame #00: (print_trace()+0x17) [0x400c30]
Frame #01: (func1(int)+0x2c) [0x400e80]
Frame #02: (func1(int)+0x22) [0x400e80]
Frame #03: (func1(int)+0x22) [0x400e80]
Frame #04: (func1(int)+0x22) [0x400e80]
Frame #05: (func1(int)+0x22) [0x400e80]
Frame #06: (func1(int)+0x22) [0x400e80]
Frame #07: (functor2::func2(int)+0x49) [0x401040]
Frame #08: (functor2::func2(int)+0x37) [0x401040]
Frame #09: (functor3::func3(int)+0x3d) [0x400ff0]
Frame #10: (functor3::func3(int)+0x27) [0x400ff0]
Frame #11: (functor4::operator()(int)+0x49) [0x400fa0]
Frame #12: (functor4::operator()(int)+0x37) [0x400fa0]
Frame #13: (func5(int)+0x3d) [0x400f00]
Frame #14: (func5(int)+0x27) [0x400f00]
Frame #15: (func6(int)+0x39) [0x400ec0]
Frame #16: (func6(int)+0x27) [0x400ec0]
Frame #17: (main+0x3f) [0x400f50]
Frame #18: (__libc_start_main+0xf0) [0x7f2d3cf50740]
Frame #19: (_start+0x29) [0x400b30]
Frame #20: (+0x29) [0x0]
All frames.

Linux下使用backtrace

g++ -Wall test_backtrace.cpp -O0 -g -ggdb -rdynamic -o test_backtrace.exe
clang++ -Wall test_backtrace.cpp -O0 -g -ggdb -rdynamic -o test_backtrace.exe

命令和输出:

./test_backtrace.exe

Frame #00: (print_trace()+0x1c) [0x40100c]
Frame #01: (func1(int)+0x2c) [0x40144c]
Frame #02: (func1(int)+0x22) [0x401442]
Frame #03: (func1(int)+0x22) [0x401442]
Frame #04: (func1(int)+0x22) [0x401442]
Frame #05: (func1(int)+0x22) [0x401442]
Frame #06: (func1(int)+0x22) [0x401442]
Frame #07: (functor2::func2(int)+0x49) [0x401699]
Frame #08: (functor2::func2(int)+0x37) [0x401687]
Frame #09: (functor3::func3(int)+0x3d) [0x40163d]
Frame #10: (functor3::func3(int)+0x27) [0x401627]
Frame #11: (functor4::operator()(int)+0x49) [0x4015f9]
Frame #12: (functor4::operator()(int)+0x37) [0x4015e7]
Frame #13: () [0x4014dd]
Frame #14: () [0x4014c7]
Frame #15: (func6(int)+0x39) [0x401499]
Frame #16: (func6(int)+0x27) [0x401487]
Frame #17: (main+0x3f) [0x40152f]
Frame #18: (__libc_start_main+0xf0) [0x7f4cfbf90830]
Frame #19: (_start+0x29) [0x400f19]

Linux下使用unwind+addr2line

g++ -Wall test_backtrace.cpp -O0 -g -ggdb -o test_backtrace.exe
clang++ -Wall test_backtrace.cpp -O0 -g -ggdb -o test_backtrace.exe

命令和输出:

./test_backtrace.exe | eval 'while read -r line || [[ -n "$line" ]]; do ADDR=${line/*[}; ADDR=${ADDR%]*}; echo "${line}"; echo "    $(addr2line -Cfpe ./test_backtrace.exe $ADDR)"; done'

Frame #00: () [0x400c8c]
    print_trace() at /mnt/d/workspace/test/test_backtrace.cpp:290
Frame #01: () [0x4010cc]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:353 (discriminator 1)
Frame #02: () [0x4010c2]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:349
Frame #03: () [0x4010c2]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:349
Frame #04: () [0x4010c2]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:349
Frame #05: () [0x4010c2]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:349
Frame #06: () [0x4010c2]
    func1(int) at /mnt/d/workspace/test/test_backtrace.cpp:349
Frame #07: () [0x401319]
    functor2::func2(int) at /mnt/d/workspace/test/test_backtrace.cpp:363
Frame #08: () [0x401307]
    functor2::func2(int) at /mnt/d/workspace/test/test_backtrace.cpp:360
Frame #09: () [0x4012bd]
    functor3::func3(int) at /mnt/d/workspace/test/test_backtrace.cpp:375
Frame #10: () [0x4012a7]
    functor3::func3(int) at /mnt/d/workspace/test/test_backtrace.cpp:371
Frame #11: () [0x401279]
    functor4::operator()(int) at /mnt/d/workspace/test/test_backtrace.cpp:385
Frame #12: () [0x401267]
    functor4::operator()(int) at /mnt/d/workspace/test/test_backtrace.cpp:382
Frame #13: () [0x40115d]
    func5(int) at /mnt/d/workspace/test/test_backtrace.cpp:395
Frame #14: () [0x401147]
    func5(int) at /mnt/d/workspace/test/test_backtrace.cpp:391
Frame #15: () [0x401119]
    func6(int) at /mnt/d/workspace/test/test_backtrace.cpp:403
Frame #16: () [0x401107]
    func6(int) at /mnt/d/workspace/test/test_backtrace.cpp:400
Frame #17: () [0x4011af]
    main at /mnt/d/workspace/test/test_backtrace.cpp:410
Frame #18: (__libc_start_main+0xf0) [0x7f2cf6390830]
    ?? ??:0
Frame #19: () [0x400b99]
    _start at ??:?

Windows环境

backtrace方案

Windows上的MinGW64里没有execinfo.h的头文件,gcc和clang都没有,所以不能用上面提到的方法。unwind.h倒是有,但是我本地试了下并没有作用,会返回一个空的0帧。于是参考了下boost.stacktraceMSDN里的做法,主要分两种

dbghelp

第一种是使用dbghelp库。先用CaptureStackBackTrace抓出执行栈的地址集合。然后使用SymFromAddr获取符号数据。

dbgeng+IDebugClient+IDebugControl+IDebugSymbols

第二种是使用dbgeng库和几个调试服务的组件IDebugClient/IDebugControl/IDebugSymbols。也是需要先用CaptureStackBackTrace抓出执行栈的地址集合。然后用IDebugClient来Attach到当前进程上,再用IDebugControl等待Attach完成,最后用IDebugSymbols导出符号数据。

boost.stacktrace就是用的第二种方法。这种方式比第一种那种更通用一些,因为导入了调试服务器,所以甚至可以使用远程调试文件。但是第二种方法再注册服务的时候有一大陀的magic number,我总觉得很不靠谱。而且需要等待Attach完成。这样的话怕是在突发性的大量使用的情况下(比如服务突然间短暂的异常,打印了茫茫多Error Log)会大幅降低性能。所以我感觉还是优先用第一种方式好一些。

不过无论哪种方法。MSVC下都必须开/Zi选项,因为这两个接口都依赖pdb文件。如果pdb文件不正确,输出的符号也会错误(函数地址是正确的),如果没有pdb文件,输出就会缺失符号信息。

以下是两种方式的编译命令和结果。

Windows+MSVC使用dbghelp

cl /nologo /W4 /DEBUG /Zi test_backtrace.cpp

命令和输出:

test_backtrace.exe

Frame 00: (print_trace) [0x00007FF6C75768F0]
Frame 01: (func1) [0x00007FF6C7576EE0]
Frame 02: (func1) [0x00007FF6C7576EE0]
Frame 03: (func1) [0x00007FF6C7576EE0]
Frame 04: (func1) [0x00007FF6C7576EE0]
Frame 05: (func1) [0x00007FF6C7576EE0]
Frame 06: (func1) [0x00007FF6C7576EE0]
Frame 07: (functor2::func2) [0x00007FF6C7578850]
Frame 08: (functor2::func2) [0x00007FF6C7578850]
Frame 09: (functor3::func3) [0x00007FF6C75788A0]
Frame 10: (functor3::func3) [0x00007FF6C75788A0]
Frame 11: (functor4::operator()) [0x00007FF6C7577D20]
Frame 12: (functor4::operator()) [0x00007FF6C7577D20]
Frame 13: (func5) [0x00007FF6C7576F10]
Frame 14: (func5) [0x00007FF6C7576F10]
Frame 15: (func6) [0x00007FF6C7576F50]
Frame 16: (func6) [0x00007FF6C7576F50]
Frame 17: (main) [0x00007FF6C7576F90]
Frame 18: (__scrt_common_main_seh) [0x00007FF6C757A078]
Frame 19: (BaseThreadInitThunk) [0x00007FFCAA081FD0]
Frame 20: (RtlUserThreadStart) [0x00007FFCAC64EF90]

Windows+MSVC使用dbgeng组件

cl /nologo /W4 /DEBUG /Zi test_backtrace.cpp

命令和输出:

test_backtrace.exe

Frame 00: (test_backtrace!print_trace) [0x00007FF6C7576921]
Frame 01: (test_backtrace!func1) [0x00007FF6C7576F03]
Frame 02: (test_backtrace!func1) [0x00007FF6C7576EFC]
Frame 03: (test_backtrace!func1) [0x00007FF6C7576EFC]
Frame 04: (test_backtrace!func1) [0x00007FF6C7576EFC]
Frame 05: (test_backtrace!func1) [0x00007FF6C7576EFC]
Frame 06: (test_backtrace!func1) [0x00007FF6C7576EFC]
Frame 07: (test_backtrace!functor2::func2) [0x00007FF6C7578889]
Frame 08: (test_backtrace!functor2::func2) [0x00007FF6C757887A]
Frame 09: (test_backtrace!functor3::func3) [0x00007FF6C75788D4]
Frame 10: (test_backtrace!functor3::func3) [0x00007FF6C75788C0]
Frame 11: (test_backtrace!functor4::operator()) [0x00007FF6C7577D59]
Frame 12: (test_backtrace!functor4::operator()) [0x00007FF6C7577D4A]
Frame 13: (test_backtrace!func5) [0x00007FF6C7576F44]
Frame 14: (test_backtrace!func5) [0x00007FF6C7576F30]
Frame 15: (test_backtrace!func6) [0x00007FF6C7576F7F]
Frame 16: (test_backtrace!func6) [0x00007FF6C7576F70]
Frame 17: (test_backtrace!main) [0x00007FF6C7576FD0]
Frame 18: (test_backtrace!__scrt_common_main_seh) [0x00007FF6C757A188]
Frame 19: (KERNEL32!BaseThreadInitThunk) [0x00007FFCAA081FE4]
Frame 20: (ntdll!RtlUserThreadStart) [0x00007FFCAC64EFB1]

Windows+MinGW64+addr2line

前面也提到了MinGW下的gcc和clang是没有execinfo.h的,unwind.h里的东西输出也是空值。所以也只能和MSVC一样使用dbghelp或者dbgeng。但是由于gcc和clang会把符号表写在二进制里而不是pdb文件里。所以解析符号必然失败。所以我们在Windows下得gcc和clang提取调用栈得时候得跳过符号解析。所幸我们仍然可以用addr2line来解析地址。所以就有了以下结果。

g++ test_backtrace.cpp -O0 -g -ggdb -o test_backtrace.exe -ldbghelp -ldbgeng -Wall -DUSING_GNU_UNWIND=0
clang++ test_backtrace.cpp -O0 -g -ggdb -o test_backtrace.exe -ldbghelp -ldbgeng -Wall -DUSING_GNU_UNWIND=0

命令和输出:

./test_backtrace.exe | eval 'while read -r line || [[ -n "$line" ]]; do ADDR=${line/*[}; ADDR=${ADDR%]*}; echo "${line}"; echo "    $(addr2line -Cfpe ./test_backtrace.exe $ADDR)"; done'

Frame 00: () [0x00000000004015b4]
    print_trace() 于 D:\workspace\test/test_backtrace.cpp:176
Frame 01: () [0x000000000040163b]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:353
Frame 02: () [0x0000000000401631]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:349
Frame 03: () [0x0000000000401631]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:349
Frame 04: () [0x0000000000401631]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:349
Frame 05: () [0x0000000000401631]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:349
Frame 06: () [0x0000000000401631]
    func1(int) 于 D:\workspace\test/test_backtrace.cpp:349
Frame 07: () [0x000000000040189d]
    functor2::func2(int) 于 D:\workspace\test/test_backtrace.cpp:363
Frame 08: () [0x000000000040188a]
    functor2::func2(int) 于 D:\workspace\test/test_backtrace.cpp:360
Frame 09: () [0x000000000040183e]
    functor3::func3(int) 于 D:\workspace\test/test_backtrace.cpp:375
Frame 10: () [0x0000000000401826]
    functor3::func3(int) 于 D:\workspace\test/test_backtrace.cpp:371
Frame 11: () [0x00000000004017ed]
    functor4::operator()(int) 于 D:\workspace\test/test_backtrace.cpp:385
Frame 12: () [0x00000000004017da]
    functor4::operator()(int) 于 D:\workspace\test/test_backtrace.cpp:382
Frame 13: () [0x00000000004016ce]
    func5(int) 于 D:\workspace\test/test_backtrace.cpp:395
Frame 14: () [0x00000000004016b6]
    func5(int) 于 D:\workspace\test/test_backtrace.cpp:391
Frame 15: () [0x0000000000401689]
    func6(int) 于 D:\workspace\test/test_backtrace.cpp:403
Frame 16: () [0x0000000000401676]
    func6(int) 于 D:\workspace\test/test_backtrace.cpp:400
Frame 17: () [0x0000000000401734]
    main 于 D:\workspace\test/test_backtrace.cpp:410
Frame 18: () [0x00000000004013f7]
    __tmainCRTStartup 于 C:/repo/mingw-w64-crt-git/src/mingw-w64/mingw-w64-crt/crt/crtexe.c:343
Frame 19: () [0x000000000040152b]
    mainCRTStartup 于 C:/repo/mingw-w64-crt-git/src/mingw-w64/mingw-w64-crt/crt/crtexe.c:221
Frame 20: () [0x00007ffcaa081fe4]
    ?? ??:0
Frame 21: () [0x00007ffcac64efb1]
    ?? ??:0

结束

以上所有测试代码和运行结果都放在 https://gist.github.com/owt5008137/78e1fea9a0221ddf9ed540f4adacf358

更完整的实现我已经放到了util代码的log模块中(log_stacktrace.hlog_stacktrace.cpp)。因为为了最小依赖,默认不会开libunwind的版本,默认windows下使用dbghelp。提取方法的检测可以写到cmake的检测脚本里,尽可能提供多的数据并且没有太高的额外开销(坚决不启动新进程,不block wait)。然后再log模块里增加了一个选项,可以控制一个范围内的错误级别,在打印原本得错误信息之后追加打印这个调用栈,这样看出错得关系得信息会更容易些。

另外utils的代码在Linux/Windows和macOS上测试过ok了。valgrind也跑过了没有问题。唯一的麻烦是不同平台的libunwind的以来库不太一样。我写了个cmake脚本会尝试去查找一下libunwind-和libunwind-generic,找不到的情况的话只手动加了。这也是默认不开libunwind的原因之一。