Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

glog library (google log) printing out `(unknown)` in stacktrace?

The glog library is printing (unknown) for certain stack frames in a stacktrace.

I'm on Ubuntu 18.04 using the standard libgoogle-glog-dev package:

$ cat > t.cc
#include <glog/logging.h>
void h() { LOG(FATAL) << "test"; }
void g() { h(); }
void f() { g(); }
int main(int argc, char** argv) {
  google::InitGoogleLogging(argv[0]);
  f();
}
^D

The above program when compiled...

$ g++ t.cc -lglog

...and run...

$ ./a.out

...outputs the following:

F1219 13:54:46.608317 13408 t.cc:3] test
*** Check failure stack trace: ***
    @     0x7f90ddd970cd  google::LogMessage::Fail()
    @     0x7f90ddd98f33  google::LogMessage::SendToLog()
    @     0x7f90ddd96c28  google::LogMessage::Flush()
    @     0x7f90ddd99999  google::LogMessageFatal::~LogMessageFatal()
    @     0x56279a0a7b30  (unknown)
    @     0x56279a0a7b45  (unknown)
    @     0x56279a0a7b51  (unknown)
    @     0x56279a0a7b77  (unknown)
    @     0x7f90dd632b97  __libc_start_main
    @     0x56279a0a79fa  (unknown)
Aborted (core dumped)

See the frames with (unknown) - I would expect them to read main, f, g, h

I've tried adding -rdynamic, but I still observe the same behaviour:

 $ g++ t.cc -lglog -rdynamic

I've tried adding -g, but I still observe the same behaviour:

 $ g++ t.cc -lglog -o t -g -rdynamic
like image 980
Andrew Tomazos Avatar asked Dec 19 '18 04:12

Andrew Tomazos


2 Answers

I just tried it and it works for me.
My result where you can see h(), g(), f() is shown in the stack trace.

F1219 16:20:16.171772 20931 main.cpp:2] test
*** Check failure stack trace: ***
    @     0x7f951ee03e6d  (unknown)
    @     0x7f951ee05ced  (unknown)
    @     0x7f951ee03a5c  (unknown)
    @     0x7f951ee0663e  (unknown)
    @           0x40089a  h()
    @           0x4008af  g()
    @           0x4008bb  f()
    @           0x4008e1  main
    @     0x7f951e22e3d5  __libc_start_main
    @           0x4007a9  (unknown)

Process finished with exit code 134 (interrupted by signal 6: SIGABRT)

Here is my CMakeLists.txt file

cmake_minimum_required(VERSION 3.13)
project(test_glog)

set(CMAKE_CXX_STANDARD 14)

include_directories(/usr/include)
link_libraries(glog)
add_executable(test_glog main.cpp)

Which expands to this when I compile:

I am on CentOS 7 and installed following libraries:

yum install glog-devel gflags-devel

Here is how I build it:

[user@cent1 build]$ make VERBOSE=1
/usr/bin/cmake3 -H/home/user/CLionProjects/test_glog -B/home/user/CLionProjects/test_glog/build --check-build-system CMakeFiles/Makefile.cmake 0
/usr/bin/cmake3 -E cmake_progress_start /home/user/CLionProjects/test_glog/build/CMakeFiles /home/user/CLionProjects/test_glog/build/CMakeFiles/progress.marks
make -f CMakeFiles/Makefile2 all
make[1]: Entering directory `/home/user/CLionProjects/test_glog/build'
make -f CMakeFiles/test_glog.dir/build.make CMakeFiles/test_glog.dir/depend
make[2]: Entering directory `/home/user/CLionProjects/test_glog/build'
cd /home/user/CLionProjects/test_glog/build && /usr/bin/cmake3 -E cmake_depends "Unix Makefiles" /home/user/CLionProjects/test_glog /home/user/CLionProjects/test_glog /home/user/CLionProjects/test_glog/build /home/user/CLionProjects/test_glog/build /home/user/CLionProjects/test_glog/build/CMakeFiles/test_glog.dir/DependInfo.cmake --color=
make[2]: Leaving directory `/home/user/CLionProjects/test_glog/build'
make -f CMakeFiles/test_glog.dir/build.make CMakeFiles/test_glog.dir/build
make[2]: Entering directory `/home/user/CLionProjects/test_glog/build'
[ 50%] Building CXX object CMakeFiles/test_glog.dir/main.cpp.o
/opt/rh/devtoolset-7/root/usr/bin/c++    -std=gnu++14 -o CMakeFiles/test_glog.dir/main.cpp.o -c /home/user/CLionProjects/test_glog/main.cpp
[100%] Linking CXX executable test_glog
/usr/bin/cmake3 -E cmake_link_script CMakeFiles/test_glog.dir/link.txt --verbose=1
/opt/rh/devtoolset-7/root/usr/bin/c++     CMakeFiles/test_glog.dir/main.cpp.o  -o test_glog -lglog 
make[2]: Leaving directory `/home/user/CLionProjects/test_glog/build'
[100%] Built target test_glog
make[1]: Leaving directory `/home/user/CLionProjects/test_glog/build'
/usr/bin/cmake3 -E cmake_progress_start /home/user/CLionProjects/test_glog/build/CMakeFiles 0

Update: I install Debian ubuntu-18.04.1-desktop-amd64.iso in a vm and build glog from sources. Your example now shows:

$ ./a.out 
F0102 23:54:15.603329 10358 t.cc:2] test
*** Check failure stack trace: ***
    @     0x55c930b28d2c  google::LogMessage::Fail()
    @     0x55c930b28c74  google::LogMessage::SendToLog()
    @     0x55c930b285b5  google::LogMessage::Flush()
    @     0x55c930b2be66  google::LogMessageFatal::~LogMessageFatal()
    @     0x55c930b25820  google::thread_msg_data
    @     0x55c930b25835  google::thread_msg_data
    @     0x55c930b25841  google::thread_msg_data
    @     0x55c930b25867  google::thread_msg_data
    @     0x7ff9fbf2eb97  __libc_start_main
    @     0x55c930b256ea  google::thread_msg_data
    @              (nil)  (unknown)
Aborted (core dumped)

I can see there we an atempt to fix this so I advice you to open an issue with glog. https://github.com/google/glog/pull/347/commits/26459400f49850bda8e736882c6f22c2ce766761

I also tried to build it straight from the command link and show the settings. Not sure if the settings for the build of the glog library would make a difference.

$ g++ t.cc -lglog --verbose
Using built-in specs.
COLLECT_GCC=g++
COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/7/lto-wrapper
OFFLOAD_TARGET_NAMES=nvptx-none
OFFLOAD_TARGET_DEFAULT=1
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Ubuntu 7.3.0-27ubuntu1~18.04' --with-bugurl=file:///usr/share/doc/gcc-7/README.Bugs --enable-languages=c,ada,c++,go,brig,d,fortran,objc,obj-c++ --prefix=/usr --with-gcc-major-version-only --program-suffix=-7 --program-prefix=x86_64-linux-gnu- --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --libdir=/usr/lib --enable-nls --with-sysroot=/ --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --with-default-libstdcxx-abi=new --enable-gnu-unique-object --disable-vtable-verify --enable-libmpx --enable-plugin --enable-default-pie --with-system-zlib --with-target-system-zlib --enable-objc-gc=auto --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --enable-multilib --with-tune=generic --enable-offload-targets=nvptx-none --without-cuda-driver --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 7.3.0 (Ubuntu 7.3.0-27ubuntu1~18.04) 
COLLECT_GCC_OPTIONS='-v' '-shared-libgcc' '-mtune=generic' '-march=x86-64'
 /usr/lib/gcc/x86_64-linux-gnu/7/cc1plus -quiet -v -imultiarch x86_64-linux-gnu -D_GNU_SOURCE t.cc -quiet -dumpbase t.cc -mtune=generic -march=x86-64 -auxbase t -version -fstack-protector-strong -Wformat -Wformat-security -o /tmp/ccoFCYTb.s
GNU C++14 (Ubuntu 7.3.0-27ubuntu1~18.04) version 7.3.0 (x86_64-linux-gnu)
    compiled by GNU C version 7.3.0, GMP version 6.1.2, MPFR version 4.0.1, MPC version 1.1.0, isl version isl-0.19-GMP

GGC heuristics: --param ggc-min-expand=100 --param ggc-min-heapsize=131072
ignoring duplicate directory "/usr/include/x86_64-linux-gnu/c++/7"
ignoring nonexistent directory "/usr/local/include/x86_64-linux-gnu"
ignoring nonexistent directory "/usr/lib/gcc/x86_64-linux-gnu/7/../../../../x86_64-linux-gnu/include"
#include "..." search starts here:
#include <...> search starts here:
 /usr/include/c++/7
 /usr/include/x86_64-linux-gnu/c++/7
 /usr/include/c++/7/backward
 /usr/lib/gcc/x86_64-linux-gnu/7/include
 /usr/local/include
 /usr/lib/gcc/x86_64-linux-gnu/7/include-fixed
 /usr/include/x86_64-linux-gnu
 /usr/include
End of search list.
GNU C++14 (Ubuntu 7.3.0-27ubuntu1~18.04) version 7.3.0 (x86_64-linux-gnu)
    compiled by GNU C version 7.3.0, GMP version 6.1.2, MPFR version 4.0.1, MPC version 1.1.0, isl version isl-0.19-GMP

GGC heuristics: --param ggc-min-expand=100 --param ggc-min-heapsize=131072
Compiler executable checksum: 1bfae38ae5df64de6196cbd8c3b07d86
COLLECT_GCC_OPTIONS='-v' '-shared-libgcc' '-mtune=generic' '-march=x86-64'
 as -v --64 -o /tmp/ccvUzQBB.o /tmp/ccoFCYTb.s
GNU assembler version 2.30 (x86_64-linux-gnu) using BFD version (GNU Binutils for Ubuntu) 2.30
COMPILER_PATH=/usr/lib/gcc/x86_64-linux-gnu/7/:/usr/lib/gcc/x86_64-linux-gnu/7/:/usr/lib/gcc/x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/7/:/usr/lib/gcc/x86_64-linux-gnu/
LIBRARY_PATH=/usr/lib/gcc/x86_64-linux-gnu/7/:/usr/lib/gcc/x86_64-linux-gnu/7/../../../x86_64-linux-gnu/:/usr/lib/gcc/x86_64-linux-gnu/7/../../../../lib/:/lib/x86_64-linux-gnu/:/lib/../lib/:/usr/lib/x86_64-linux-gnu/:/usr/lib/../lib/:/usr/lib/gcc/x86_64-linux-gnu/7/../../../:/lib/:/usr/lib/
COLLECT_GCC_OPTIONS='-v' '-shared-libgcc' '-mtune=generic' '-march=x86-64'
 /usr/lib/gcc/x86_64-linux-gnu/7/collect2 -plugin /usr/lib/gcc/x86_64-linux-gnu/7/liblto_plugin.so -plugin-opt=/usr/lib/gcc/x86_64-linux-gnu/7/lto-wrapper -plugin-opt=-fresolution=/tmp/ccNEOWk1.res -plugin-opt=-pass-through=-lgcc_s -plugin-opt=-pass-through=-lgcc -plugin-opt=-pass-through=-lc -plugin-opt=-pass-through=-lgcc_s -plugin-opt=-pass-through=-lgcc --sysroot=/ --build-id --eh-frame-hdr -m elf_x86_64 --hash-style=gnu --as-needed -dynamic-linker /lib64/ld-linux-x86-64.so.2 -pie -z now -z relro /usr/lib/gcc/x86_64-linux-gnu/7/../../../x86_64-linux-gnu/Scrt1.o /usr/lib/gcc/x86_64-linux-gnu/7/../../../x86_64-linux-gnu/crti.o /usr/lib/gcc/x86_64-linux-gnu/7/crtbeginS.o -L/usr/lib/gcc/x86_64-linux-gnu/7 -L/usr/lib/gcc/x86_64-linux-gnu/7/../../../x86_64-linux-gnu -L/usr/lib/gcc/x86_64-linux-gnu/7/../../../../lib -L/lib/x86_64-linux-gnu -L/lib/../lib -L/usr/lib/x86_64-linux-gnu -L/usr/lib/../lib -L/usr/lib/gcc/x86_64-linux-gnu/7/../../.. /tmp/ccvUzQBB.o -lglog -lstdc++ -lm -lgcc_s -lgcc -lc -lgcc_s -lgcc /usr/lib/gcc/x86_64-linux-gnu/7/crtendS.o /usr/lib/gcc/x86_64-linux-gnu/7/../../../x86_64-linux-gnu/crtn.o
COLLECT_GCC_OPTIONS='-v' '-shared-libgcc' '-mtune=generic' '-march=x86-64'

Here is the output when I run it:

$ ./a.out 
F0106 12:07:11.753652 28547 t.cc:2] test
*** Check failure stack trace: ***
    @     0x55c500dedd2c  google::LogMessage::Fail()
    @     0x55c500dedc74  google::LogMessage::SendToLog()
    @     0x55c500ded5b5  google::LogMessage::Flush()
    @     0x55c500df0e66  google::LogMessageFatal::~LogMessageFatal()
    @     0x55c500dea820  google::thread_msg_data
    @     0x55c500dea835  google::thread_msg_data
    @     0x55c500dea841  google::thread_msg_data
    @     0x55c500dea867  google::thread_msg_data
    @     0x7f882d938b97  __libc_start_main
    @     0x55c500dea6ea  google::thread_msg_data
    @              (nil)  (unknown)
Aborted (core dumped)

Update 2: A glog developer Evgeny Prigorodov have been looking into the problem and have identified the issue. I am confident this issue will be fixed soon.

So here is what happens in src/symbolize.cc after a93a451:

Each line in the stack trace is being prepared in the function SymbolizeAndDemangle(). It calculates variables start_address / base_address and calls the function GetSymbolFromObjectFile(), which tries to look up symbol corresponding to a given frame instruction pointer (pc).

In v0.3.4 the call to GetSymbolFromObjectFile() passed value of start_address, a start address of a memory region, which can never be zero. GetSymbolFromObjectFile() did not check the value of start_address and just used it for lookups in two symbol tables.

In v0.3.5 the call to GetSymbolFromObjectFile() started passing value of base_address. That value can become zero if the frame program counter was found within the very first memory region and the executable image has been mapped with zero offset. That seems to be a common case.

Another change in GetSymbolFromObjectFile() added a code for symbol offset adjustment and a new check: if symbol_offset equals zero after all adjustments then the function returns a failure value meaning "symbol not found". Since the symbol_offset variable was then calculated from base_address, that condition became quite possible.

For full details see

like image 107
Damian Avatar answered Oct 21 '22 01:10

Damian


That seem to be a regression introduced in the glog v0.3.5 by this commit.

The sample code works correctly when compiled in Ubuntu 16.04 with the stock version of libgoogle-glog-dev v0.3.4

And the problem can be reliably reproduced on the AWS Ubuntu Server 18.04 (AMI ID ami-00035f41c82244dab) with the stock version of libgoogle-glog-dev v0.3.5.

Downgrading package libgoogle-glog-dev to version v0.3.4 fixes the problem on Ubuntu 18.04.

In order to downgrade the version apply the following workaround: 1) add Xenial repository with the previous versions and 2) make apt prefer the version 0.3.4 of libgoogle-glog-dev to (a.k.a package pinning):

ubuntu@ec-ubuntu18:~$ dpkg -l | grep glog
ii  libgoogle-glog-dev               0.3.5-1                           amd64        library that implements application-level logging.
ii  libgoogle-glog0v5                0.3.5-1                           amd64        library that implements application-level logging.

ubuntu@ec-ubuntu18:~$ ./a.out 
F0108 19:22:08.617049 19750 t.cc:2] test
*** Check failure stack trace: ***
    @     0x7ffa821240cd  google::LogMessage::Fail()
    @     0x7ffa82125f33  google::LogMessage::SendToLog()
    @     0x7ffa82123c28  google::LogMessage::Flush()
    @     0x7ffa82126999  google::LogMessageFatal::~LogMessageFatal()
    @     0x563949dd89c0  (unknown)
    @     0x563949dd89d5  (unknown)
    @     0x563949dd89e1  (unknown)
    @     0x563949dd8a07  (unknown)
    @     0x7ffa819bfb97  __libc_start_main
    @     0x563949dd888a  (unknown)
Aborted (core dumped)

ubuntu@ec-ubuntu18:~$ echo "deb http://archive.ubuntu.com/ubuntu/ xenial universe" | sudo tee /etc/apt/sources.list.d/xenial.list
ubuntu@ec-ubuntu18:~$ cat << EOF | sudo tee /etc/apt/preferences.d/libgoogle-glog-dev
# Pin down the version of google-glog
Package: libgoogle-glog-dev libgoogle-glog0v5
Pin: version 0.3.4*
Pin-Priority: 1000

# Make sure that other packages from Xenial cannot be installed
Package: *
Pin: release v=16.04, l=Ubuntu
Pin-Priority: -10
EOF

ubuntu@ec-ubuntu18:~$ sudo apt-get update
ubuntu@ec-ubuntu18:~$ sudo apt-get upgrade libgoogle-glog-dev

ubuntu@ec-ubuntu18:~$ dpkg -l | grep glog
ii  libgoogle-glog-dev               0.3.4-0.1                         amd64        library that implements application-level logging.
ii  libgoogle-glog0v5                0.3.4-0.1                         amd64        library that implements application-level logging.

ubuntu@ec-ubuntu18:~$ ./a.out 
F0108 19:30:42.793792 19518 t.cc:2] test
*** Check failure stack trace: ***
    @     0x7f3da453f5cd  google::LogMessage::Fail()
    @     0x7f3da4541433  google::LogMessage::SendToLog()
    @     0x7f3da453f15b  google::LogMessage::Flush()
    @     0x7f3da4541e1e  google::LogMessageFatal::~LogMessageFatal()
    @     0x5625c9e069c0  h()
    @     0x5625c9e069d5  g()
    @     0x5625c9e069e1  f()
    @     0x5625c9e06a07  main
    @     0x7f3da3ddbb97  __libc_start_main
    @     0x5625c9e0688a  _start
Aborted (core dumped)

I have checked that reverting commit changes in lines 359 and 806 of the source package also fixes the issue on Ubuntu 18.04.

like image 30
void Avatar answered Oct 21 '22 03:10

void