libbacktrace icon indicating copy to clipboard operation
libbacktrace copied to clipboard

Libbacktrace fails to resolve symbols, even though the debug information is present

Open jeremy-rifkin opened this issue 2 years ago • 5 comments

I am trying to generate stacktraces with libbacktrace. They are working locally, but on a github workflow runner I'm seeing this

test/test.cpp||18||trace()
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
test/test.cpp||35||foo(int)
||0||
||0||
||0||
||0||
||0||
||0||
||0||
||0||
||0||
test/test.cpp||43||function_two(int, float)
test/test.cpp||48||function_one(int)
test/test.cpp||52||main
||0||
||0||
||0||

I expect to see this:

test/test.cpp||18||trace()
test/test.cpp||31||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||33||foo(int)
test/test.cpp||39||void foo<int>(int, int)
test/test.cpp||39||void foo<int, int>(int, int, int)
test/test.cpp||39||void foo<int, int, int>(int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int>(int, int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int, int>(int, int, int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int, int, int>(int, int, int, int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int, int, int, int>(int, int, int, int, int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int, int, int, int, int>(int, int, int, int, int, int, int, int, int)
test/test.cpp||39||void foo<int, int, int, int, int, int, int, int, int>(int, int, int, int, int, int, int, int, int, int)
test/test.cpp||43||function_two(int, float)
test/test.cpp||47||function_one(int)
test/test.cpp||51||main
../csu/libc-start.c||308||__libc_start_main
||0||
||0||

When I run readelf --debug-dump=info test | grep foo on the github workflow runner I get this:

    <6590>   DW_AT_name        : (indirect string, offset: 0x96b4): foo<int>
    <6597>   DW_AT_linkage_name: (indirect string, offset: 0x7967): _Z3fooIJiEEviDpT_
    <65dc>   DW_AT_name        : (indirect string, offset: 0x422): foo<int, int>
    <65e3>   DW_AT_linkage_name: (indirect string, offset: 0x9535): _Z3fooIJiiEEviDpT_
    <6635>   DW_AT_name        : (indirect string, offset: 0x5264): foo<int, int, int>
    <663c>   DW_AT_linkage_name: (indirect string, offset: 0x8ba0): _Z3fooIJiiiEEviDpT_
    <669b>   DW_AT_name        : (indirect string, offset: 0x945e): foo<int, int, int, int>
    <66a2>   DW_AT_linkage_name: (indirect string, offset: 0x2d92): _Z3fooIJiiiiEEviDpT_
    <6756>   DW_AT_name        : (indirect string, offset: 0x0): foo<int, int, int, int, int>
    <675d>   DW_AT_linkage_name: (indirect string, offset: 0x87bb): _Z3fooIJiiiiiEEviDpT_
    <6922>   DW_AT_name        : (indirect string, offset: 0x2de7): foo<int, int, int, int, int, int>
    <6929>   DW_AT_linkage_name: (indirect string, offset: 0x415d): _Z3fooIJiiiiiiEEviDpT_
    <6b0e>   DW_AT_name        : (indirect string, offset: 0x94ae): foo<int, int, int, int, int, int, int>
    <6b15>   DW_AT_linkage_name: (indirect string, offset: 0x1fac): _Z3fooIJiiiiiiiEEviDpT_
    <6d18>   DW_AT_name        : (indirect string, offset: 0x43c5): foo<int, int, int, int, int, int, int, int>
    <6d1f>   DW_AT_linkage_name: (indirect string, offset: 0x7f9): _Z3fooIJiiiiiiiiEEviDpT_
    <7061>   DW_AT_name        : (indirect string, offset: 0x3686): foo<int, int, int, int, int, int, int, int, int>
    <7068>   DW_AT_linkage_name: (indirect string, offset: 0xb54): _Z3fooIJiiiiiiiiiEEviDpT_
    <745a>   DW_AT_name        : foo
    <7461>   DW_AT_linkage_name: (indirect string, offset: 0x7b0b): _Z3fooi

The symbols are present in the binary, but for some reason libbacktrace fails to resolve them. What could cause this?

jeremy-rifkin avatar Jul 03 '23 01:07 jeremy-rifkin

The erroneous output is from using g++-10, -std=c++11, and ubuntu-22.04

jeremy-rifkin avatar Jul 03 '23 01:07 jeremy-rifkin

libbacktrace works by looking up a PC value in the address ranges recorded by functions. The mere presence of the function name in the info section doesn't tell us much. What matters is the associated address ranges, and whether the PC values found on the stack are in those ranges.

Is there a way that I can reproduce the problem?

ianlancetaylor avatar Jul 03 '23 01:07 ianlancetaylor

Hi, thanks so much for the reply. I have my implementation at https://github.com/jeremy-rifkin/cpptrace/blob/4dac00a87f749752ca4a042c55806e71550da2e0/src/full/full_trace_with_libbacktrace.cpp and the test program at https://github.com/jeremy-rifkin/cpptrace/blob/4dac00a87f749752ca4a042c55806e71550da2e0/test/test.cpp It might be possible to reproduce with the following:

git clone https://github.com/jeremy-rifkin/cpptrace.git
git checkout 4dac00a
mkdir build
cd build
cmake .. \
   -DCMAKE_BUILD_TYPE=Debug \
   -DCMAKE_CXX_COMPILER=g++-10 \
   -DCMAKE_CXX_STANDARD=11 \
   -DCPPTRACE_FULL_TRACE_WITH_LIBBACKTRACE=On \
   -DCPPTRACE_BUILD_TEST=On
make
./test

As an update, I was able to get at least the symbol names by falling back to backtrace_syminfo https://github.com/jeremy-rifkin/cpptrace/blob/4dac00a87f749752ca4a042c55806e71550da2e0/src/symbols/symbols_with_libbacktrace.cpp#L59-L73 (this is a slightly different back-end that takes addresses from execinfo.h rather than backtrace_full).

Is there a reason why the file/line information would not be retrievable but the symbol would be?

jeremy-rifkin avatar Jul 03 '23 02:07 jeremy-rifkin

I have constructed a better reproducible example that reproduces locally for me:

repro_lib.cpp
#include <iostream>
#include <vector>
#include <string>
#include <cstddef>

#include <linux/limits.h>
#include <unistd.h>

#include <backtrace.h>

struct stacktrace_frame {
    uintptr_t address;
    int line;
    int col;
    std::string filename;
    std::string symbol;
};

struct trace_data {
    std::vector<stacktrace_frame>& frames;
    size_t& skip;
};

int full_callback(void* data_pointer, uintptr_t address, const char* file, int line, const char* symbol) {
    trace_data& data = *reinterpret_cast<trace_data*>(data_pointer);
    if(data.skip > 0) {
        data.skip--;
    } else {
        data.frames.push_back({
            address,
            line,
            -1,
            file ? file : "",
            symbol ? symbol : ""
        });
    }
    return 0;
}

void syminfo_callback(void* data, uintptr_t, const char* symbol, uintptr_t, uintptr_t) {
    stacktrace_frame& frame = *static_cast<stacktrace_frame*>(data);
    frame.symbol = symbol ? symbol : "";
}

void error_callback(void*, const char*, int) {
    // nothing for now
}

backtrace_state* get_backtrace_state() {
    // backtrace_create_state must be called only one time per program
    static backtrace_state* state = nullptr;
    static bool called = false;
    if(!called) {
        state = backtrace_create_state(nullptr, true, error_callback, nullptr);
        called = true;
    }
    return state;
}

std::vector<stacktrace_frame> generate_trace(size_t skip) {
    std::vector<stacktrace_frame> frames;
    skip++; // add one for this call
    trace_data data { frames, skip };
    backtrace_full(get_backtrace_state(), 0, full_callback, error_callback, &data);
    for(auto& frame : frames) {
        if(frame.symbol.empty()) {
            // fallback, try to at least recover the symbol name with backtrace_syminfo
            backtrace_syminfo(
                get_backtrace_state(),
                reinterpret_cast<uintptr_t>(frame.address),
                syminfo_callback,
                error_callback,
                &frame
            );
        }
    }
    return frames;
}
repro.cpp
#include <iostream>
#include <vector>
#include <string>
#include <cstddef>

struct stacktrace_frame {
    uintptr_t address;
    int line;
    int col;
    std::string filename;
    std::string symbol;
};

std::vector<stacktrace_frame> generate_trace(size_t skip);

void trace() {
    for(const auto& frame : generate_trace(0)) {
        std::cout
            << frame.filename
            << "||"
            << frame.line
            << "||"
            << frame.symbol
            << std::endl;
    }
}

void foo(int n) {
    if(n == 0) {
        trace();
    } else {
        foo(n - 1);
    }
}

template<typename... Args>
void foo(int x, Args... args) {
    foo(args...);
}

void function_two(int, float) {
    foo(1, 2, 3, 4, 5, 6, 7, 8, 9, 10);
}

void function_one(int) {
    function_two(0, 0);
}

int main() {
    function_one(0);
}
/usr/bin/c++ -g -std=c++14 -fPIC -Wall -Wextra -Werror=return-type -Wshadow -o repro_lib.o -c repro_lib.cpp
/usr/bin/ar qc librepro_lib.a repro_lib.o
/usr/bin/ranlib librepro_lib.a

/usr/bin/c++ -g -fPIE -o repro.o -c repro.cpp
/usr/bin/c++ -g repro.o -o repro librepro_lib.a -lbacktrace

It is an issue with static linking it seems. Doing it as a shared library works.

/usr/bin/c++ -g -std=c++14 -fPIC -Wall -Wextra -Werror=return-type -Wshadow -o repro_lib.o -c repro_lib.cpp
/usr/bin/c++ -fPIC -g -shared -Wl,-soname,repro_lib.so -o repro_lib.so repro_lib.o -lbacktrace

/usr/bin/c++ -g -fPIE -o repro.o -c repro.cpp
/usr/bin/c++ -g repro.o -o repro  -Wl,-rpath,. repro_lib.so

jeremy-rifkin avatar Jul 03 '23 21:07 jeremy-rifkin

It looks like I'm running into the same issues when I have an executable -> a.so -> b.so (which then invokes libbacktrace).

jeremy-rifkin avatar Jul 15 '23 18:07 jeremy-rifkin