google / glog

C++ implementation of the Google logging module
http://google.github.io/glog/
BSD 3-Clause "New" or "Revised" License
6.93k stars 2.05k forks source link

The log output buffer doesn't get flushed correctly when printing the stack trace #1102

Closed bertulli closed 1 month ago

bertulli commented 1 month ago

Hi, thank you for your work! This is really a very intuitive library.

I'm trying to make the output of the stack trace written to the log file, as well as the stderr. So I wrote a simple failure writer function, and I initialize the library like this:

void failureWriter(const char* data, int size) {
  char error_buffer[4096];
  memcpy(error_buffer, data, size);
  char* err = strtok(error_buffer, "\n");
  while (err) {
    LOG(ERROR) << err;
    err = strtok(NULL, "\n");
  }

}

int main(int argc, char *argv[])
{
  // Init logging library
  google::InitGoogleLogging(argv[0]);
  google::InstallFailureSignalHandler();
  google::InstallFailureWriter(failureWriter);

  google::SetLogDestination(google::WARNING, "");
  google::SetLogDestination(google::ERROR, "");

[...]
}

In my program, I try to elicit a segmentation fault by dereferencing an invalid memory pointer. When compiling without the google::InstallFailureWriter(failureWriter) call, I get this:

*** Aborted at 1718016867 (unix time) try "date -d @1718016867" if you are using GNU date ***
PC: @   0x4047fa main
*** SIGSEGV (@0xa65e6800) received by PID 13421 (TID 0x76f425f0) from PID 18446744072205789184; stack trace: ***
    @ 0x76c1afe0 (unknown)
    @   0x4047fa main
    @ 0x76c0c4aa __libc_start_main

but when I compile with it, I get:

E0610 12:53:05.303339 13336 main.cpp:23] *** Aborted at 1718016785 (unix time) try "date -d @1718016785" if you are using GNU date ***
E0610 12:53:05.304879 13336 main.cpp:23] PC: @   0x40885a main
E0610 12:53:05.306208 13336 main.cpp:23] *** SIGSEGV (@0xa65b7800) received by PID 13336 (TID 0x76f135f0) from PID 18446744072205596672; stack trace: ***
E0610 12:53:05.308718 13336 main.cpp:23]     @ 0x76bebfe0 (unknown)
E0610 12:53:05.310195 13336 main.cpp:23]     @   0x40885a main
E0610 12:53:05.311108 13336 main.cpp:23] own)          // <---- NOTE HERE!!!!
E0610 12:53:05.312759 13336 main.cpp:23]     @ 0x76bdd4aa __libc_start_main

Notice the spurious own). Without looking at the source code, I note that the exceeding part is, in "pointers", one char less than the difference between the two previous prints

    @ 0x76c1afe0 (unknown)
    @   0x4047fa main
                     ^   ^
                     ⌊___⌋

May it be an issue of buffer synchronization/mutual exclusion/not flushing? Thanks!

sergiud commented 1 month ago

Your failure writer function is flawed. Specifically, std::strtok expects a null-terminated string while data is not.

sergiud commented 1 month ago

The glog user guide clarifies this as well now.