Pre-fatal-log hook for usage before the fata log is sent to sinks

This commit is contained in:
Kjell Hedstrom 2015-02-22 23:31:17 -07:00
parent a768d2146a
commit a69eb201a1
6 changed files with 106 additions and 20 deletions

View File

@ -113,6 +113,13 @@ void RaiseSIGABRTAndAccessViolation() {
f2.wait();
}
void ThrowInt() {
throw 1233210;
}
void FailedCHECK() {
CHECK(false) << "This is fatal";
}
void CallActualExitFunction(std::function<void()> fatal_function) {
fatal_function();
@ -122,6 +129,8 @@ void CallExitFunction(std::function<void()> fatal_function) {
CallActualExitFunction(fatal_function);
}
void ExecuteDeathFunction(const bool runInNewThread, int fatalChoice) {
std::cout << "Calling :" << __FUNCTION__ << " Line: " << __LINE__ << std::endl << std::flush;
auto exitFunction = &NoExitFunction;
@ -136,7 +145,8 @@ void ExecuteDeathFunction(const bool runInNewThread, int fatalChoice) {
case 8: exitFunction = &OutOfBoundsArrayIndexing; break;
case 9: exitFunction = &AccessViolation; break;
case 10: exitFunction = &RaiseSIGABRTAndAccessViolation; break;
case 11: throw 1233210; break;
case 11: exitFunction = &ThrowInt; break;
case 12: exitFunction = &FailedCHECK; break;
default: break;
}
if (runInNewThread) {
@ -192,14 +202,16 @@ int ChoiceOfFatalExit() {
std::cout << "[8] Out of bounds array indexing " << std::endl;
std::cout << "[9] Access violation" << std::endl;
std::cout << "[10] Rasing SIGABRT + Access Violation in two separate threads" << std::endl;
std::cout << "[11] Just throw" << std::endl;
std::cout << "[11] Just throw (in this thread)" << std::endl;
std::cout << "[12] Just CHECK(false) (in this thread)" << std::endl;
std::cout << std::flush;
try {
std::getline(std::cin, option);
choice = std::stoi(option);
if (choice <= 0 || choice > 11) {
if (choice <= 0 || choice > 12) {
std::cout << "Invalid choice: [" << option << "\n\n";
} else {
return choice;

View File

@ -18,13 +18,13 @@
#include <sstream>
#include <atomic>
#include <process.h> // getpid
#define getpid _getpid
#include "crashhandler.hpp"
#include "stacktrace_windows.hpp"
#include "g2logmessage.hpp"
#include "g2logmessagecapture.hpp"
#define getpid _getpid
namespace {
std::atomic<bool> gBlockForFatal {true};
LPTOP_LEVEL_EXCEPTION_FILTER g_previous_unexpected_exception_handler = nullptr;
@ -85,6 +85,8 @@ void signalHandler(int signal_number) {
// For fatal signals only, not exceptions.
// This is a way to tell the IDE (if in dev mode) that it can stop at this breakpoint
// Note that at this time the fatal log event with stack trace is NOT yet flushed to the logger
// This call will do nothing unless we're in DEBUG and "DEBUG_BREAK_AT_FATAL_SIGNAL" is enabled
// ref: g3log/Options.cmake
#if (!defined(NDEBUG) && defined(DEBUG_BREAK_AT_FATAL_SIGNAL))
__debugbreak();
#endif
@ -105,8 +107,8 @@ LONG WINAPI exceptionHandling(EXCEPTION_POINTERS* info, const std::string& handl
LogCapture trigger(g2::internal::FATAL_EXCEPTION, fatal_id, dump.c_str());
trigger.stream() << fatal_stream.str();
// FATAL Exception: It doesn't necessarily stop here we pass on continue search
// if no one else will catch that then it's goodbye anyhow,
// the RISK here is if someone is cathing this and returning "EXCEPTION_EXECUTE_HANDLER"
// if no one else will catch that then it's goodbye anyhow.
// The RISK here is if someone is cathing this and returning "EXCEPTION_EXECUTE_HANDLER"
// but does not shutdown then the software will be running with g3log shutdown.
// .... However... this must be seen as a bug from standard handling of fatal exceptions
// https://msdn.microsoft.com/en-us/library/6wxdsc38.aspx
@ -127,7 +129,9 @@ LONG WINAPI unexpectedExceptionHandling(EXCEPTION_POINTERS* info) {
LONG WINAPI vectorExceptionHandling(PEXCEPTION_POINTERS p) {
const g2::SignalType exception_code = p->ExceptionRecord->ExceptionCode;
if (false == stacktrace::isKnownException(exception_code)) {
LOG(WARNING) << "Vectored exception handling received an UNKNOWN exception: " << exception_code << ". The exception is IGNORED and hopefully caught by another exception handler";
// The unknown exception is ignored. Since it is not a Windows
// fatal exception generated by the OS we leave the
// responsibility to deal with this by the client software.
return EXCEPTION_CONTINUE_SEARCH;
} else {
ReverseToOriginalFatalHandling();

View File

@ -38,6 +38,8 @@ std::mutex g_logging_init_mutex;
std::unique_ptr<g2::LogMessage> g_first_unintialized_msg = {nullptr};
std::once_flag g_set_first_uninitialized_flag;
std::once_flag g_save_first_unintialized_flag;
const std::function<void(void)> g_pre_fatal_hook_that_does_nothing = []{ /*does nothing */};
std::function<void(void)> g_fatal_pre_logging_hook;
}
@ -52,7 +54,7 @@ namespace g2 {
// for all other practical use, it shouldn't!
void initializeLogging(LogWorker* bgworker) {
std::call_once(g_initialize_flag, []() {
std::call_once(g_initialize_flag, [] {
installCrashHandler();
});
std::lock_guard<std::mutex> lock(g_logging_init_mutex);
@ -67,6 +69,9 @@ void initializeLogging(LogWorker* bgworker) {
});
g_logger_instance = bgworker;
// by default the pre fatal logging hook does nothing
// if it WOULD do something it would happen in
internal::setFatalPreLoggingHook(g_pre_fatal_hook_that_does_nothing);
}
@ -120,6 +125,8 @@ void saveMessage(const char* entry, const char* file, int line, const char* func
if (internal::wasFatal(level)) {
message.get()->write().append(stack_trace);
FatalMessagePtr fatal_message {std2::make_unique<FatalMessage>(*(message._move_only.get()), fatal_signal)};
g_fatal_pre_logging_hook(); // pre-fatal hook
// At destruction, flushes fatal message to g2LogWorker
// either we will stay here until the background worker has received the fatal
// message, flushed the crash message to the sinks and exits with the same fatal signal
@ -178,6 +185,17 @@ void pushFatalMessageToLogger(FatalMessagePtr message) {
}
/**
* default does nothing, @ref ::g_pre_fatal_hook_that_does_nothing
* It will be called just before sending the fatal message, @ref pushFatalmessageToLogger
* It will be reset to do nothing in ::initializeLogging(...)
* so please call this function, if you ever need to, after initializeLogging(...)
*/
void setFatalPreLoggingHook(std::function<void(void)> pre_fatal_hook) {
g_fatal_pre_logging_hook = pre_fatal_hook;
}
// By default this function pointer goes to \ref pushFatalMessageToLogger;
std::function<void(FatalMessagePtr) > g_fatal_to_g2logworker_function_ptr = pushFatalMessageToLogger;

View File

@ -56,6 +56,16 @@ namespace g2 {
void initializeLogging(LogWorker *logger);
//
// internal namespace is for completely internal or semi-hidden from the g2 namespace due to that it is unlikely
// that you will use these
// That said:
// 1) setFatalExitHandler() can be used to set your own custom fatal handler. Please see g2log.cpp
// so that you shut down and clean up fatal handlers in a good way
//
// 2) setFatalPreLoggingHook() can be used for either an extra step before the fatalExitHandler is called
// examples here could be "cleanup" while keeping the normal default fatal handler
// another good example is to put a break point in programatically
namespace internal {
/// @returns true if logger is initialized
bool isLoggingInitialized();
@ -86,6 +96,26 @@ namespace g2 {
// to sinks as well as shutting down the process
void fatalCall(FatalMessagePtr message);
// Set a function-hook before a fatal message will be sent to the logger
// i.e. this is a great place to put a break point, either in your debugger
// or programatically to catch LOG(FATAL), CHECK(...) or an OS fatal event (exception or signal)
// This will be reset to default (does nothing) at initializeLogging(...);
//
// Example usage:
// Windows: g2::SetPreFatalHook([]{__debugbreak();}); // remember #include <intrin.h>
// Linux: g2::SetPreFatalHook([]{ raise(SIGTRAP); });
void setFatalPreLoggingHook(std::function<void(void)> pre_fatal_hook);
/** By default the g2log will call g2LogWorker::fatalCall(...) which will
* abort() the system after flushing the logs to file. This makes unit
* test of FATAL level cumbersome. A work around is to change the
* 'fatal call' which can be done here
* The bool return values in the fatal_call is whether or not the fatal_call should
*
*/
void setFatalExitHandler(std::function<void(FatalMessagePtr)> fatal_call);
// Shuts down logging. No object cleanup but further LOG(...) calls will be ignored.
void shutDownLogging();
@ -93,16 +123,6 @@ namespace g2 {
// Shutdown logging, but ONLY if the active logger corresponds to the one currently initialized
bool shutDownLoggingForActiveOnly(LogWorker* active);
/** By default the g2log will call g2LogWorker::fatal(...) which will
* abort() the system after flushing the logs to file. This makes unit
* test of FATAL level cumbersome. A work around is to change the
* 'fatal call' which can be done here
*
* The bool return values in the fatal_call is whether or not the fatal_call should
*
*/
void setFatalExitHandler(std::function<void(FatalMessagePtr)> fatal_call);
} // internal

View File

@ -77,4 +77,4 @@ option (USE_G3LOG_UNIT_TEST
ENDIF()
ELSE()
MESSAGE("-DUSE_G3LOG_UNIT_TEST=OFF")
ENDIF (USE_G3LOG_UNIT_TEST)
ENDIF (USE_G3LOG_UNIT_TEST)

View File

@ -26,6 +26,12 @@ const std::string t_debug = "test DEBUG ";
const std::string t_debug2 = "test DEBUG 1.123456";
const std::string t_warning = "test WARNING ";
const std::string t_warning2 = "test WARNING yello";
std::atomic<size_t> g_fatal_counter = {0};
void fatalCounter() {
++g_fatal_counter;
}
} // end anonymous namespace
@ -266,9 +272,35 @@ TEST(LogTest, LOGF__FATAL) {
EXPECT_TRUE(verifyContent(file_content, "This message should throw 0")) << "\n****" << file_content;
EXPECT_TRUE(verifyContent(file_content, "FATAL"));
}
TEST(LogTest, LOG_preFatalLogging_hook) {
{
RestoreFileLogger logger(log_directory);
ASSERT_FALSE(mockFatalWasCalled());
g_fatal_counter.store(0);
g2::internal::setFatalPreLoggingHook(fatalCounter);
LOG(FATAL) << "This message is fatal";
logger.reset();
EXPECT_EQ(g_fatal_counter.load(), 1);
}
{ // Now with no fatal pre-logging-hook
RestoreFileLogger logger(log_directory);
ASSERT_FALSE(mockFatalWasCalled());
g_fatal_counter.store(0);
LOG(FATAL) << "This message is fatal";
EXPECT_EQ(g_fatal_counter.load(), 0);
}
}
TEST(LogTest, LOG_FATAL) {
RestoreFileLogger logger(log_directory);
ASSERT_FALSE(mockFatalWasCalled());
LOG(FATAL) << "This message is fatal";
EXPECT_TRUE(mockFatalWasCalled());
EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by "));