Custom InstallFailureFunction does not prevent exit

[oliverdain]

I want to convert the CHECK macro so that failure throw an exception rather than calling abort. Putting aside the difficulty that the function registered with InstallFailureFunction is called from a destructor, I can't even get it to do nothing.

Here's my test:

// Eventually will hopefully throw an exception but for now it just does nothing so
// as to (theoretically) prevent abort/exit from being called.
void ThrowingFailureFunction() {
  LOG(ERROR) << "Was bad things did happen.";
}

void FailureThrowInsteadOfExit() {
  google::InstallFailureFunction(&ThrowingFailureFunction);
}

// In test file
void FailingCheckFunction() {
  CHECK(false) << "Well that wasn't good!";
}

TEST(InitLogging, CanConvertCheckToThrow) {
  FailureThrowInsteadOfExit();
  FailingCheckFunction();
}

As I understand it the call to FailingCheckFunction should cause a FATAL level log, that should call ThrowingFailureFunction which should log something but not exit/abort. That isn't what happens. My ThrowingFailureFunction does get called and it does log, but then the glog google::logging_fail function gets called. When I step through it in a debugger I'm see that LogMessage::Fail is called which, as expected, calls my failure function. However, upon return the debugger jumps immediately to logging_fail and the debugger just shows an extra stack frame that says "unknown source" so neither it nor I know how it go there or what called that function.

So I really have a series of questions here:

1. How do I prevent a LOG(FATAL) or CHECK fail from calling abort?
2. Would there then be a safe way to have it throw an exception instead? Seems safe-ish as it'd throw from the last line of the LogMessage destructor, but ugly...
3. If I can throw, I'd like my exception to include the log line (e.g. whatever was sent to the LOG(FATAL) stream) but the callback isn't passed any objects so I don't know how to access the message.

Clearly I can define my own CHECK macro and use that but I'm also using 3rd party code which uses glog and I can easily fix all of that.

[geoffviola]

The noreturn attribute applied to the interfaces of InstallFailureFunction and LogMessage::Fail() cause this behavior. The compiler will generate code that will not return from the function as it does normally.

Since the problem is in the API, it's possible to #undef and reimplement the *_FATAL macros in https://github.com/google/glog/blob/master/src/glog/logging.h.in. Then, define a class like LogMessageFatal, which throws in the destructor. Note that this class would be able to extend to other class that throw in the destructor.

One of the tricky bits is that LogMessage::SendToLog still calls Fail(). The unit tests get around this by calling an internal function:

glog/src/logging_unittest.cc

Lines 85 to 92 in 7f91846

	_START_GOOGLE_NAMESPACE_
	namespace base {
	namespace internal {
	bool GetExitOnDFatal();
	void SetExitOnDFatal(bool value);
	} // namespace internal
	} // namespace base
	_END_GOOGLE_NAMESPACE_

.

All of these changes could be done without modifying glog. It would be nice if there was cleaner solution for not calling Fail. Also, it would be nice if DumpStackTraceToString was exposed to the public API: #144.

[geoffviola]

Just to revise the previous comment. It's safe to throw in a function with the noreturn attribute. The above mentioned user sided implementation should still work.

There are multiple issues in the current implementation.

1. Fail() is called in ~LogMessageFatal() and then in LogMessage(). An exception after an exception before a catch will cause a call to std::terminate.
2. In C++11, destructors are noexcept(true) by default. To implement a call to throw, they must have noexcept(false).

[nh2]

@sergiud What was the solution here?

[sarlinpe]

Indeed there is no good solution to this. It is a problem for us, certainly affects many others too, and a strong case for not using glog. @sergiud I believe this issue should be reopened.

[sergiud]

@sarlinpe Why do you believe there is no good solution to this? At least in @oliverdain's case, marking the LogMessageFatal destructor as noexcept(false) should allow throwing exceptions instead of invoking std::abort, no?

[sarlinpe]

You are right, it was only a bit more work:

namespace google {

template <typename T>
class LogMessageFatalThrow : public LogMessage {
 public:
  LogMessageFatalThrow(const char* file, int line)
      : LogMessage(file, line, GLOG_ERROR, &message_) {};
  LogMessageFatalThrow(const char* file, int line, std::string* message)
      : LogMessage(file, line, GLOG_ERROR, message), message_(*message) {};
  LogMessageFatalThrow(const char* file, int line, const CheckOpString& result)
      : LogMessage(file, line, GLOG_ERROR, &message_) {
    stream() << "Check failed: " << (*result.str_) << " ";
    // On LOG(FATAL) glog does not bother cleaning up CheckOpString so we do so here.
    delete result.str_;
  };
  [[noreturn]] ~LogMessageFatalThrow() noexcept(false) {
    Flush();
    throw T(message_);
  };

 private:
  std::string message_;
};

using LogMessageFatalThrowDefault = LogMessageFatalThrow<std::invalid_argument>;

template <typename T>
T ThrowCheckNotNull(const char* file, int line, const char* names, T&& t) {
  if (t == nullptr) {
    LogMessageFatalThrowDefault(file, line, new std::string(names));
  }
  return std::forward<T>(t);
}
}  // namespace google

#undef COMPACT_GOOGLE_LOG_FATAL
#define COMPACT_GOOGLE_LOG_FATAL \
  google::LogMessageFatalThrowDefault(__FILE__, __LINE__)

#undef LOG_TO_STRING_FATAL
#define LOG_TO_STRING_FATAL(message) \
  google::LogMessageFatalThrowDefault(__FILE__, __LINE__, message)

#define LOG_FATAL_CUSTOM(exception) \
    google::LogMessageFatalThrow<exception>(__FILE__, __LINE__).stream()

#undef CHECK_OP
#define CHECK_OP(name, op, val1, val2) \
  CHECK_OP_LOG(name, op, val1, val2, google::LogMessageFatalThrowDefault)

#undef CHECK_NOTNULL
#define CHECK_NOTNULL(val)   \
  google::ThrowCheckNotNull( \
      __FILE__, __LINE__, "'" #val "' Must be non NULL", (val))

I am happy to contribute this back if it is useful, for example as documentation. Still, I do believe that glog could make this kind of extension a little easier, e.g. with a macro #define LOG_MESSAGE_FATAL_CLASS google::LogMessageFatal that can be redefined.

[sergiud]

Is there a reason there's a new class for this purpose? Can't we reuse LogMessageFatal (with the updated destructor) and InstallFailureFunction to setup a handler that throws? The exception type is known at compile-time. Thus existing functionality should be sufficient to support your use case.

[sarlinpe]

If I understand you correctly, you are suggesting this:

class LogMessageFatalThrow : public LogMessageFatal {
  using LogMessageFatal::LogMessageFatal;
 public:
  ~LogMessageFatalThrow() noexcept(false) {};
};

void ThrowingFailureFunction() {
  throw std::invalid_argument("Fatal error");
}

google::InstallFailureFunction(&ThrowingFailureFunction);

// additional macros re-definitions

This always ends up with an std::terminate - presumably because Fail() gets called multiple times. Throwing in the destructor instead seg faults.

[sergiud]

Yes, this is what I had in mind. Indeed, std::terminate is called because the failure function is invoked in the destructor while the stack is unwound due to previous failure function invocation. However, this should be easy to fix.

Please see 5645f3a and let me know if this works for you.

[sarlinpe]

Thanks, this indeed works. Some remaining issues:

1. For CHECK_OP calls, this induces a memory leak because CheckOpString is not cleaned up
   

   glog/src/glog/logging.h

   Lines 609 to 612 in 5645f3a

   	struct CheckOpString {
   	CheckOpString(std::string* str) : str_(str) {}
   	// No destructor: if str_ is non-nullptr, we're about to LOG(FATAL),
   	// so there's no point in cleaning up str_.

2. The logs are printed twice (nit)

F20240131 10:56:34.466309 140360896700416 main.cc:202] Check failed: value == 0 (1 vs. 0)
*** Check failure stack trace: ***
F20240131 10:56:34.466309 140360896700416 main.cc:202] Check failed: value == 0 (1 vs. 0)
*** Check failure stack trace: ***

[sergiud]

Thanks for testing! Hopefully 772e325 fixes the remaining issues.