From 626191a62d6791f107ffc1d201e27faf57381801 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Kjell=20Hedstr=C3=B6m=20-=20seeking=20Senior=20Engineering?= =?UTF-8?q?=20roles=20as=20well=20as=20contract=20opportunities?= Date: Tue, 5 Dec 2023 23:33:03 -0700 Subject: [PATCH] Mostly a refactor of tests (#513) --- .vscode/launch.json | 6 +- .vscode/settings.json | 7 +- src/crashhandler_unix.cpp | 27 ++- src/crashhandler_windows.cpp | 28 ++- src/g3log.cpp | 4 +- src/g3log/crashhandler.hpp | 1 + src/g3log/g3log.hpp | 2 +- test_unit/Test.cmake | 2 +- test_unit/test_fatal.cpp | 349 +++++++++++++++++++++++++++++++++++ test_unit/test_io.cpp | 308 ------------------------------- test_unit/test_signal.cpp | 62 +++++++ 11 files changed, 467 insertions(+), 329 deletions(-) create mode 100644 test_unit/test_fatal.cpp create mode 100644 test_unit/test_signal.cpp diff --git a/.vscode/launch.json b/.vscode/launch.json index 77a1bac..b1ceb77 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -12,10 +12,9 @@ "name": "(gdb) Start", "type": "cppdbg", "request": "launch", - "program": "${workspaceFolder}/build/g3log-FATAL-contract", + "program": "${workspaceFolder}/build/test_signal", "MIMode": "gdb", - "cwd": "${workspaceFolder}/build" - "setupCommands": [ + "cwd": "${workspaceFolder}/build""setupCommands": [ { "description": "Enable pretty-printing for gdb", "text": "-enable-pretty-printing", @@ -28,6 +27,5 @@ } ] } - ] } \ No newline at end of file diff --git a/.vscode/settings.json b/.vscode/settings.json index 09894bb..f861bed 100644 --- a/.vscode/settings.json +++ b/.vscode/settings.json @@ -1,4 +1,7 @@ { "cmake.configureOnOpen": false, - "editor.formatOnSave": true -} + "editor.formatOnSave": true, + "files.associations": { + "ostream": "cpp" + } +} \ No newline at end of file diff --git a/src/crashhandler_unix.cpp b/src/crashhandler_unix.cpp index dacb575..924c21b 100644 --- a/src/crashhandler_unix.cpp +++ b/src/crashhandler_unix.cpp @@ -242,6 +242,30 @@ namespace g3 { exit(signal_number); } + // This function is intended to be async-signal-safe. Using write and STDERR_FILENO should be + // safe in a signal handler. ref: http://pubs.opengroup.org/onlinepubs/009695399/functions/write.html + + // This function is intended to be async-signal-safe. + // It writes an error message to stderr using the write system call, + // which is listed as async-signal-safe by POSIX. + size_t writeErrorMessage(const char* message) { + if (message == nullptr) { + return 0; + } + + // Calculate the length of the message without using std library strlen or similar + // this is to ensure async-signal-safe by POSIX + size_t length = 0; + for (const char* p = message; *p != '\0'; ++p) { + ++length; + } + + // Write the message to STDERR_FILENO in a single call. + // This assumes that the message is not too large for a single write. + auto bytes_written = write(STDERR_FILENO, message, length); + return bytes_written; + } + // restores the signal handler back to default void restoreFatalHandlingToDefault() { #if !(defined(DISABLE_FATAL_SIGNALHANDLING)) @@ -274,7 +298,8 @@ namespace g3 { if (sigaction(signal_number, &(old_action_it->second), nullptr) < 0) { auto signalname = std::string("sigaction - ") + signalToStr(signal_number); - perror(signalname.c_str()); + // https://man7.org/linux/man-pages/man7/signal-safety.7.html (see signal-safety) + internal::writeErrorMessage(signalname.c_str()); } gSavedSigActions.erase(old_action_it); diff --git a/src/crashhandler_windows.cpp b/src/crashhandler_windows.cpp index d4a5b39..757ab98 100644 --- a/src/crashhandler_windows.cpp +++ b/src/crashhandler_windows.cpp @@ -14,6 +14,7 @@ #include #include #include +#include #include #include "g3log/crashhandler.hpp" #include "g3log/g3log.hpp" @@ -171,6 +172,13 @@ namespace g3 { raise(signal_number); } + // FYI: Concept of async-signal-safe operations does not exist on windows + // we stick to perror for lack of better alternatives. + size_t writeErrorMessage(const char* message) { + perror(message); + return std::strlen(message); + } + // Restore back to default fatal event handling void restoreFatalHandlingToDefault() { #if !(defined(DISABLE_FATAL_SIGNALHANDLING)) @@ -181,19 +189,19 @@ namespace g3 { #endif if (SIG_ERR == signal(SIGABRT, SIG_DFL)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); if (SIG_ERR == signal(SIGFPE, SIG_DFL)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); if (SIG_ERR == signal(SIGSEGV, SIG_DFL)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); if (SIG_ERR == signal(SIGILL, SIG_DFL)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); if (SIG_ERR == signal(SIGTERM, SIG_DFL)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); #endif } @@ -212,15 +220,15 @@ namespace g3 { if (!g_installed_thread_signal_handler) { g_installed_thread_signal_handler = true; if (SIG_ERR == signal(SIGTERM, signalHandler)) - perror("signal - SIGTERM"); + internal::writeErrorMessage("signal - SIGTERM"); if (SIG_ERR == signal(SIGABRT, signalHandler)) - perror("signal - SIGABRT"); + internal::writeErrorMessage("signal - SIGABRT"); if (SIG_ERR == signal(SIGFPE, signalHandler)) - perror("signal - SIGFPE"); + internal::writeErrorMessage("signal - SIGFPE"); if (SIG_ERR == signal(SIGSEGV, signalHandler)) - perror("signal - SIGSEGV"); + internal::writeErrorMessage("signal - SIGSEGV"); if (SIG_ERR == signal(SIGILL, signalHandler)) - perror("signal - SIGILL"); + internal::writeErrorMessage("signal - SIGILL"); } #endif } diff --git a/src/g3log.cpp b/src/g3log.cpp index fa35e41..a5bfa52 100644 --- a/src/g3log.cpp +++ b/src/g3log.cpp @@ -148,13 +148,13 @@ namespace g3 { message.get()->setExpression(boolean_expression); if (internal::wasFatal(level)) { - saveFatalMessage(level, stack_trace, message, fatal_signal); + saveFatalMessage(stack_trace, message, fatal_signal); } else { pushMessageToLogger(message); } } - void saveFatalMessage(const LEVELS& level, const char* stack_trace, g3::LogMessagePtr& message, int& fatal_signal) { + void saveFatalMessage(const char* stack_trace, g3::LogMessagePtr& message, int& fatal_signal) { auto fatalhook = g_fatal_pre_logging_hook; // In case the fatal_pre logging actually will cause a crash in its turn // let's not do recursive crashing! diff --git a/src/g3log/crashhandler.hpp b/src/g3log/crashhandler.hpp index a3fbdb1..941e1e1 100644 --- a/src/g3log/crashhandler.hpp +++ b/src/g3log/crashhandler.hpp @@ -77,5 +77,6 @@ namespace g3 { * This is an internal only function. Do not use it elsewhere. It is triggered * from g3log, g3LogWorker after flushing messages to file */ void exitWithDefaultSignalHandler(const LEVELS& level, g3::SignalType signal_number); + size_t writeErrorMessage(const char* message); } // namespace internal } // namespace g3 diff --git a/src/g3log/g3log.hpp b/src/g3log/g3log.hpp index 37c5450..af5363d 100644 --- a/src/g3log/g3log.hpp +++ b/src/g3log/g3log.hpp @@ -106,7 +106,7 @@ namespace g3 { void saveMessage(const char* message, const char* file, int line, const char* function, const LEVELS& level, const char* boolean_expression, int fatal_signal, const char* stack_trace); - void saveFatalMessage(const LEVELS& level, const char* stack_trace, g3::LogMessagePtr& message, int& fatal_signal); + void saveFatalMessage(const char* stack_trace, g3::LogMessagePtr& message, int& fatal_signal); // forwards the message to all sinks void pushMessageToLogger(LogMessagePtr log_entry); diff --git a/test_unit/Test.cmake b/test_unit/Test.cmake index 3a28639..d272af0 100644 --- a/test_unit/Test.cmake +++ b/test_unit/Test.cmake @@ -62,7 +62,7 @@ SET(OS_SPECIFIC_TEST test_crashhandler_windows) ENDIF(MSVC OR MINGW) - SET(tests_to_run test_message test_filechange test_io test_cpp_future_concepts test_concept_sink test_sink ${OS_SPECIFIC_TEST}) + SET(tests_to_run test_message test_filechange test_io test_fatal test_signal test_cpp_future_concepts test_concept_sink test_sink ${OS_SPECIFIC_TEST}) SET(helper ${DIR_UNIT_TEST}/testing_helpers.h ${DIR_UNIT_TEST}/testing_helpers.cpp) include_directories(${DIR_UNIT_TEST}) diff --git a/test_unit/test_fatal.cpp b/test_unit/test_fatal.cpp new file mode 100644 index 0000000..e34213e --- /dev/null +++ b/test_unit/test_fatal.cpp @@ -0,0 +1,349 @@ +/** ==========================================================================re + * 2011 by KjellKod.cc. This is PUBLIC DOMAIN to use at your own risk and comes + * with no warranties. This code is yours to share, use and modify with no + * strings attached and no restrictions or obligations. + * + * For more information see g3log/LICENSE or refer refer to http://unlicense.org + * ============================================================================*/ + +#include +#include "g3log/g3log.hpp" +#include "g3log/generated_definitions.hpp" +#include "g3log/loglevels.hpp" +#include "g3log/logworker.hpp" +#include "testing_helpers.h" + +#include +#include +#include +#include +#include +#include +#include +#include + +namespace { + const std::string log_directory = "./"; + const std::string t_info = "test INFO "; + const std::string t_info2 = "test INFO 123"; + const std::string t_debug = "test DEBUG "; + const std::string t_debug3 = "test DEBUG 1.123456"; + const std::string t_warning = "test WARNING "; + const std::string t_warning3 = "test WARNING yello"; + + std::atomic g_fatal_counter = {0}; + void fatalCounter() { + ++g_fatal_counter; + } + +} // end anonymous namespace + +using namespace testing_helpers; +TEST(LogTest, LOGF__FATAL) { + RestoreFileLogger logger(log_directory); + ASSERT_FALSE(mockFatalWasCalled()); + LOGF(FATAL, "This message should throw %d", 0); + EXPECT_TRUE(mockFatalWasCalled()); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw 0")) << "\n****" << mockFatalMessage(); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); + + auto file_content = logger.resetAndRetrieveContent(); + EXPECT_TRUE(verifyContent(file_content, "This message should throw 0")) << "\n****" << file_content; + EXPECT_TRUE(verifyContent(file_content, "FATAL")); +} + +#ifndef DISABLE_FATAL_SIGNALHANDLING + +TEST(LogTest, FatalSIGTERM__UsingDefaultHandler) { + RestoreFileLogger logger(log_directory); + g_fatal_counter.store(0); + g3::setFatalPreLoggingHook(fatalCounter); + raise(SIGTERM); + logger.reset(); + EXPECT_EQ(g_fatal_counter.load(), size_t{1}); +} + +#if !(defined(WIN32) || defined(_WIN32) || defined(__WIN32__)) +namespace { + std::atomic customFatalCounter = {0}; + std::atomic lastEncounteredSignal = {0}; + void customSignalHandler(int signal_number, siginfo_t* info, void* unused_context) { + lastEncounteredSignal.store(signal_number); + ++customFatalCounter; + } + void installCustomSIGTERM() { + struct sigaction action; + memset(&action, 0, sizeof(action)); + sigemptyset(&action.sa_mask); + action.sa_sigaction = &customSignalHandler; + action.sa_flags = SA_SIGINFO; + sigaction(SIGTERM, &action, nullptr); + } + + std::atomic oldSigTermCheck = {false}; + void customOldSignalHandler(int signal_number, siginfo_t* info, void* unused_context) { + lastEncounteredSignal.store(signal_number); + oldSigTermCheck.store(true); + } + void installCustomOldSIGTERM() { + struct sigaction action; + memset(&action, 0, sizeof(action)); + sigemptyset(&action.sa_mask); + action.sa_sigaction = &customOldSignalHandler; + action.sa_flags = SA_SIGINFO; + sigaction(SIGTERM, &action, nullptr); + } + +} // namespace + +// Override of signal handling and testing of it should be fairly easy to port to windows +// ref: https://github.com/KjellKod/g3log/blob/master/src/crashhandler_windows.cpp +// what is missing is the override of signals and custom installation of signals +// ref: https://github.com/KjellKod/g3log/blob/master/src/crashhandler_unix.cpp +// functions: void restoreFatalHandlingToDefault() +// void overrideSetupSignals(const std::map overrideSignals) +// void restoreSignalHandler(int signal_number) +// +// It would require some adding of unit test (see the test below) +// and good Windows experience. Since I am not currently working much on the Windows +// side I am reaching out to the community for this one: +// +// +// For the test to work the following code should be added in this test +//void customSignalHandler(int signal_number) { +// lastEncounteredSignal.store(signal_number); +// ++customFatalCounter; +//} +// +//void installCustomSIGTERM() { +// ASSERT_TRUE(SIG_ERR != signal(SIGTERM, customSignalHandler)); +//} + +TEST(LogTest, FatalSIGTERM__UsingCustomHandler) { + RestoreFileLogger logger(log_directory); + g_fatal_counter.store(0); + g3::setFatalPreLoggingHook(fatalCounter); + installCustomSIGTERM(); + g3::overrideSetupSignals({{SIGABRT, "SIGABRT"}, {SIGFPE, "SIGFPE"}, {SIGILL, "SIGILL"}}); + + installCustomSIGTERM(); + EXPECT_EQ(customFatalCounter.load(), size_t{0}); + EXPECT_EQ(lastEncounteredSignal.load(), 0); + + raise(SIGTERM); + logger.reset(); + EXPECT_EQ(g_fatal_counter.load(), size_t{0}); + EXPECT_EQ(lastEncounteredSignal.load(), SIGTERM); + EXPECT_EQ(customFatalCounter.load(), size_t{1}); +} + +TEST(LogTest, FatalSIGTERM__VerifyingOldCustomHandler) { + RestoreFileLogger logger(log_directory); + g_fatal_counter.store(0); + customFatalCounter.store(0); + lastEncounteredSignal.store(0); + + g3::setFatalPreLoggingHook(fatalCounter); + installCustomOldSIGTERM(); + g3::overrideSetupSignals({{SIGABRT, "SIGABRT"}, {SIGFPE, "SIGFPE"}, {SIGILL, "SIGILL"}, {SIGTERM, "SIGTERM"}}); + g3::restoreSignalHandler(SIGTERM); // revert SIGTERM installation + + EXPECT_EQ(customFatalCounter.load(), size_t{0}); + EXPECT_EQ(lastEncounteredSignal.load(), 0); + EXPECT_FALSE(oldSigTermCheck.load()); + raise(SIGTERM); + logger.reset(); + EXPECT_EQ(g_fatal_counter.load(), size_t{0}); + EXPECT_EQ(lastEncounteredSignal.load(), SIGTERM); + EXPECT_TRUE(oldSigTermCheck.load()); +} + +#endif // DISABLE_FATAL_SIGNALHANDLING +#endif // !(defined(WIN32) || defined(_WIN32) || defined(__WIN32__)) + +TEST(LogTest, LOG_preFatalLogging_hook) { + { + RestoreFileLogger logger(log_directory); + ASSERT_FALSE(mockFatalWasCalled()); + g_fatal_counter.store(0); + g3::setFatalPreLoggingHook(fatalCounter); + LOG(FATAL) << "This message is fatal"; + logger.reset(); + EXPECT_EQ(g_fatal_counter.load(), size_t{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(), size_t{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 ")); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message is fatal")) + << "\ncontent: [[" << mockFatalMessage() << "]]"; + EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); + + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(file_content, "This message is fatal")); + EXPECT_TRUE(verifyContent(file_content, "FATAL")); + EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); +} +TEST(LogTest, LOGF_IF__FATAL) { + RestoreFileLogger logger(log_directory); + EXPECT_FALSE(mockFatalWasCalled()); + LOGF_IF(FATAL, (2 < 3), "This message %s be worse", "could"); + EXPECT_TRUE(mockFatalWasCalled()); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")) << "\n" + << mockFatalMessage(); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message could be worse")); + + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(file_content, "FATAL")); + EXPECT_TRUE(verifyContent(file_content, "This message could be worse")); +} +TEST(LogTest, LOG_IF__FATAL) { + RestoreFileLogger logger(log_directory); + LOG_IF(WARNING, (0 != t_info.compare(t_info))) << "This message should NOT be written"; + EXPECT_FALSE(mockFatalWasCalled()); + LOG_IF(FATAL, (0 != t_info.compare(t_info2))) << "This message should throw. xyz "; + EXPECT_TRUE(mockFatalWasCalled()); + + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw. xyz ")); + + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(file_content, "FATAL")); + EXPECT_TRUE(verifyContent(file_content, "This message should throw. xyz ")); +} +TEST(LogTest, LOG_IF__FATAL__NO_THROW) { + RestoreFileLogger logger(log_directory); + LOG_IF(FATAL, (2 > 3)) << "This message%sshould NOT throw"; + ASSERT_FALSE(mockFatalWasCalled()); +} + +// CHECK_F +TEST(CheckTest, CHECK_F__thisWILL_PrintErrorMsg) { + RestoreFileLogger logger(log_directory); + EXPECT_TRUE(mockFatalMessage().empty()); + EXPECT_FALSE(mockFatalWasCalled()); + + CHECK(1 == 2); + EXPECT_FALSE(mockFatalMessage().empty()); + EXPECT_TRUE(mockFatalWasCalled()); + + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(file_content, "CONTRACT")) << "**** " << mockFatalMessage(); +} + +TEST(CHECK_F_Test, CHECK_F__thisWILL_PrintErrorMsg) { + RestoreFileLogger logger(log_directory); + std::string msg = "This message is added to throw %s and %s"; + std::string arg1 = "message"; + std::string arg3 = "log"; + + CHECK_F(1 >= 2, msg.c_str(), arg1.c_str(), arg3.c_str()); + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(file_content, "CONTRACT")); +} + +TEST(CHECK_Test, CHECK__thisWILL_PrintErrorMsg) { + RestoreFileLogger logger(log_directory); + std::string msg = "This message is added to throw message and log"; + CHECK(1 >= 2) << msg; + + logger.reset(); + std::string file_content = readFileToText(logger.logFile()); + EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); + EXPECT_TRUE(verifyContent(file_content, "CONTRACT")); + EXPECT_TRUE(verifyContent(file_content, msg)); +} +TEST(CHECK, CHECK_ThatWontThrow) { + RestoreFileLogger logger(log_directory); + std::string msg = "This %s should never appear in the %s"; + std::string msg3 = "This message should never appear in the log"; + CHECK(1 == 1); + CHECK_F(1 == 1, msg.c_str(), "message", "log"); + logger.reset(); + EXPECT_FALSE(mockFatalWasCalled()); + + std::string file_content = readFileToText(logger.logFile()); + EXPECT_FALSE(verifyContent(file_content, msg3)); + EXPECT_FALSE(verifyContent(mockFatalMessage(), msg3)); +} + +TEST(CHECK, CHECK_runtimeError) { + RestoreFileLogger logger(log_directory); + + g3::setFatalExitHandler([](g3::FatalMessagePtr msg) { + throw std::runtime_error("fatal test handler"); + }); + + class dynamic_int_array { + std::unique_ptr data_; + const int size_; + + public: + explicit dynamic_int_array(int size) : + data_{std::make_unique(size)}, + size_(size) {} + + int& at(int i) { + CHECK(i < size_); + + // unreachable if i >= size_ + return data_[i]; + } + }; + + dynamic_int_array arr{3}; + + EXPECT_THROW(arr.at(3) = 1, std::runtime_error); +} + +// see also test_io -- AddNonFatal +TEST(CustomLogLevels, AddFatal) { + RestoreFileLogger logger(log_directory); + const LEVELS DEADLY{FATAL.value + 1, {"DEADLY"}}; + EXPECT_TRUE(g3::internal::wasFatal(DEADLY)); + g_fatal_counter.store(0); + ASSERT_FALSE(mockFatalWasCalled()); + g3::setFatalPreLoggingHook(fatalCounter); +#ifdef G3_DYNAMIC_LOGGING + g3::only_change_at_initialization::addLogLevel(DEADLY, true); +#endif + // clang-format off + LOG(DEADLY) << "Testing my own custom level"; auto line = __LINE__; + // clang-format on + logger.reset(); + ASSERT_TRUE(mockFatalWasCalled()); + EXPECT_EQ(size_t{1}, g_fatal_counter.load()); + + std::string file_content = readFileToText(logger.logFile()); + std::string expected; + expected += "DEADLY [test_fatal.cpp->" + std::string(G3LOG_PRETTY_FUNCTION) + ":" + std::to_string(line); + EXPECT_TRUE(verifyContent(file_content, expected)) << file_content + << "\n\nExpected: \n" + << expected; + g_fatal_counter.store(0); // restore +} diff --git a/test_unit/test_io.cpp b/test_unit/test_io.cpp index 93b2585..95eaa78 100644 --- a/test_unit/test_io.cpp +++ b/test_unit/test_io.cpp @@ -327,288 +327,6 @@ TEST(LogTest, LOG_IF) { EXPECT_TRUE(verifyContent(file_content, t_info2)); EXPECT_FALSE(verifyContent(file_content, t_debug3)); } -TEST(LogTest, LOGF__FATAL) { - RestoreFileLogger logger(log_directory); - ASSERT_FALSE(mockFatalWasCalled()); - LOGF(FATAL, "This message should throw %d", 0); - EXPECT_TRUE(mockFatalWasCalled()); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw 0")) << "\n****" << mockFatalMessage(); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); - - auto file_content = logger.resetAndRetrieveContent(); - EXPECT_TRUE(verifyContent(file_content, "This message should throw 0")) << "\n****" << file_content; - EXPECT_TRUE(verifyContent(file_content, "FATAL")); -} - -#ifndef DISABLE_FATAL_SIGNALHANDLING - -TEST(LogTest, FatalSIGTERM__UsingDefaultHandler) { - RestoreFileLogger logger(log_directory); - g_fatal_counter.store(0); - g3::setFatalPreLoggingHook(fatalCounter); - raise(SIGTERM); - logger.reset(); - EXPECT_EQ(g_fatal_counter.load(), size_t{1}); -} - -#if !(defined(WIN32) || defined(_WIN32) || defined(__WIN32__)) -namespace { - std::atomic customFatalCounter = {0}; - std::atomic lastEncounteredSignal = {0}; - void customSignalHandler(int signal_number, siginfo_t* info, void* unused_context) { - lastEncounteredSignal.store(signal_number); - ++customFatalCounter; - } - void installCustomSIGTERM() { - struct sigaction action; - memset(&action, 0, sizeof(action)); - sigemptyset(&action.sa_mask); - action.sa_sigaction = &customSignalHandler; - action.sa_flags = SA_SIGINFO; - sigaction(SIGTERM, &action, nullptr); - } - - std::atomic oldSigTermCheck = {false}; - void customOldSignalHandler(int signal_number, siginfo_t* info, void* unused_context) { - lastEncounteredSignal.store(signal_number); - oldSigTermCheck.store(true); - } - void installCustomOldSIGTERM() { - struct sigaction action; - memset(&action, 0, sizeof(action)); - sigemptyset(&action.sa_mask); - action.sa_sigaction = &customOldSignalHandler; - action.sa_flags = SA_SIGINFO; - sigaction(SIGTERM, &action, nullptr); - } - -} // namespace - -// Override of signal handling and testing of it should be fairly easy to port to windows -// ref: https://github.com/KjellKod/g3log/blob/master/src/crashhandler_windows.cpp -// what is missing is the override of signals and custom installation of signals -// ref: https://github.com/KjellKod/g3log/blob/master/src/crashhandler_unix.cpp -// functions: void restoreFatalHandlingToDefault() -// void overrideSetupSignals(const std::map overrideSignals) -// void restoreSignalHandler(int signal_number) -// -// It would require some adding of unit test (see the test below) -// and good Windows experience. Since I am not currently working much on the Windows -// side I am reaching out to the community for this one: -// -// -// For the test to work the following code should be added in this test -//void customSignalHandler(int signal_number) { -// lastEncounteredSignal.store(signal_number); -// ++customFatalCounter; -//} -// -//void installCustomSIGTERM() { -// ASSERT_TRUE(SIG_ERR != signal(SIGTERM, customSignalHandler)); -//} - -TEST(LogTest, FatalSIGTERM__UsingCustomHandler) { - RestoreFileLogger logger(log_directory); - g_fatal_counter.store(0); - g3::setFatalPreLoggingHook(fatalCounter); - installCustomSIGTERM(); - g3::overrideSetupSignals({{SIGABRT, "SIGABRT"}, {SIGFPE, "SIGFPE"}, {SIGILL, "SIGILL"}}); - - installCustomSIGTERM(); - EXPECT_EQ(customFatalCounter.load(), size_t{0}); - EXPECT_EQ(lastEncounteredSignal.load(), 0); - - raise(SIGTERM); - logger.reset(); - EXPECT_EQ(g_fatal_counter.load(), size_t{0}); - EXPECT_EQ(lastEncounteredSignal.load(), SIGTERM); - EXPECT_EQ(customFatalCounter.load(), size_t{1}); -} - -TEST(LogTest, FatalSIGTERM__VerifyingOldCustomHandler) { - RestoreFileLogger logger(log_directory); - g_fatal_counter.store(0); - customFatalCounter.store(0); - lastEncounteredSignal.store(0); - - g3::setFatalPreLoggingHook(fatalCounter); - installCustomOldSIGTERM(); - g3::overrideSetupSignals({{SIGABRT, "SIGABRT"}, {SIGFPE, "SIGFPE"}, {SIGILL, "SIGILL"}, {SIGTERM, "SIGTERM"}}); - g3::restoreSignalHandler(SIGTERM); // revert SIGTERM installation - - EXPECT_EQ(customFatalCounter.load(), size_t{0}); - EXPECT_EQ(lastEncounteredSignal.load(), 0); - EXPECT_FALSE(oldSigTermCheck.load()); - raise(SIGTERM); - logger.reset(); - EXPECT_EQ(g_fatal_counter.load(), size_t{0}); - EXPECT_EQ(lastEncounteredSignal.load(), SIGTERM); - EXPECT_TRUE(oldSigTermCheck.load()); -} - -#endif - -#endif - -TEST(LogTest, LOG_preFatalLogging_hook) { - { - RestoreFileLogger logger(log_directory); - ASSERT_FALSE(mockFatalWasCalled()); - g_fatal_counter.store(0); - g3::setFatalPreLoggingHook(fatalCounter); - LOG(FATAL) << "This message is fatal"; - logger.reset(); - EXPECT_EQ(g_fatal_counter.load(), size_t{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(), size_t{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 ")); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message is fatal")) - << "\ncontent: [[" << mockFatalMessage() << "]]"; - EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); - - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(file_content, "This message is fatal")); - EXPECT_TRUE(verifyContent(file_content, "FATAL")); - EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); -} -TEST(LogTest, LOGF_IF__FATAL) { - RestoreFileLogger logger(log_directory); - EXPECT_FALSE(mockFatalWasCalled()); - LOGF_IF(FATAL, (2 < 3), "This message %s be worse", "could"); - EXPECT_TRUE(mockFatalWasCalled()); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")) << "\n" - << mockFatalMessage(); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message could be worse")); - - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(file_content, "FATAL")); - EXPECT_TRUE(verifyContent(file_content, "This message could be worse")); -} -TEST(LogTest, LOG_IF__FATAL) { - RestoreFileLogger logger(log_directory); - LOG_IF(WARNING, (0 != t_info.compare(t_info))) << "This message should NOT be written"; - EXPECT_FALSE(mockFatalWasCalled()); - LOG_IF(FATAL, (0 != t_info.compare(t_info2))) << "This message should throw. xyz "; - EXPECT_TRUE(mockFatalWasCalled()); - - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL")); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw. xyz ")); - - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(file_content, "FATAL")); - EXPECT_TRUE(verifyContent(file_content, "This message should throw. xyz ")); -} -TEST(LogTest, LOG_IF__FATAL__NO_THROW) { - RestoreFileLogger logger(log_directory); - LOG_IF(FATAL, (2 > 3)) << "This message%sshould NOT throw"; - ASSERT_FALSE(mockFatalWasCalled()); -} - -// CHECK_F -TEST(CheckTest, CHECK_F__thisWILL_PrintErrorMsg) { - RestoreFileLogger logger(log_directory); - EXPECT_TRUE(mockFatalMessage().empty()); - EXPECT_FALSE(mockFatalWasCalled()); - - CHECK(1 == 2); - EXPECT_FALSE(mockFatalMessage().empty()); - EXPECT_TRUE(mockFatalWasCalled()); - - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(file_content, "CONTRACT")) << "**** " << mockFatalMessage(); -} - -TEST(CHECK_F_Test, CHECK_F__thisWILL_PrintErrorMsg) { - RestoreFileLogger logger(log_directory); - std::string msg = "This message is added to throw %s and %s"; - std::string arg1 = "message"; - std::string arg3 = "log"; - - CHECK_F(1 >= 2, msg.c_str(), arg1.c_str(), arg3.c_str()); - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(file_content, "CONTRACT")); -} - -TEST(CHECK_Test, CHECK__thisWILL_PrintErrorMsg) { - RestoreFileLogger logger(log_directory); - std::string msg = "This message is added to throw message and log"; - CHECK(1 >= 2) << msg; - - logger.reset(); - std::string file_content = readFileToText(logger.logFile()); - EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by ")); - EXPECT_TRUE(verifyContent(file_content, "CONTRACT")); - EXPECT_TRUE(verifyContent(file_content, msg)); -} -TEST(CHECK, CHECK_ThatWontThrow) { - RestoreFileLogger logger(log_directory); - std::string msg = "This %s should never appear in the %s"; - std::string msg3 = "This message should never appear in the log"; - CHECK(1 == 1); - CHECK_F(1 == 1, msg.c_str(), "message", "log"); - logger.reset(); - EXPECT_FALSE(mockFatalWasCalled()); - - std::string file_content = readFileToText(logger.logFile()); - EXPECT_FALSE(verifyContent(file_content, msg3)); - EXPECT_FALSE(verifyContent(mockFatalMessage(), msg3)); -} - -TEST(CHECK, CHECK_runtimeError) { - RestoreFileLogger logger(log_directory); - - g3::setFatalExitHandler([](g3::FatalMessagePtr msg) { - throw std::runtime_error("fatal test handler"); - }); - - class dynamic_int_array { - std::unique_ptr data_; - const int size_; - - public: - explicit dynamic_int_array(int size) : - data_{std::make_unique(size)}, - size_(size) {} - - int& at(int i) { - CHECK(i < size_); - - // unreachable if i >= size_ - return data_[i]; - } - }; - - dynamic_int_array arr{3}; - - EXPECT_THROW(arr.at(3) = 1, std::runtime_error); -} TEST(CustomLogLevels, AddANonFatal) { RestoreFileLogger logger(log_directory); @@ -628,32 +346,6 @@ TEST(CustomLogLevels, AddANonFatal) { << expected; } -TEST(CustomLogLevels, AddFatal) { - RestoreFileLogger logger(log_directory); - const LEVELS DEADLY{FATAL.value + 1, {"DEADLY"}}; - EXPECT_TRUE(g3::internal::wasFatal(DEADLY)); - g_fatal_counter.store(0); - ASSERT_FALSE(mockFatalWasCalled()); - g3::setFatalPreLoggingHook(fatalCounter); -#ifdef G3_DYNAMIC_LOGGING - g3::only_change_at_initialization::addLogLevel(DEADLY, true); -#endif - // clang-format off - LOG(DEADLY) << "Testing my own custom level"; auto line = __LINE__; - // clang-format on - logger.reset(); - ASSERT_TRUE(mockFatalWasCalled()); - EXPECT_EQ(size_t{1}, g_fatal_counter.load()); - - std::string file_content = readFileToText(logger.logFile()); - std::string expected; - expected += "DEADLY [test_io.cpp->" + std::string(G3LOG_PRETTY_FUNCTION) + ":" + std::to_string(line); - EXPECT_TRUE(verifyContent(file_content, expected)) << file_content - << "\n\nExpected: \n" - << expected; - g_fatal_counter.store(0); // restore -} - #ifdef G3_DYNAMIC_LOGGING namespace { // Restore dynamic levels if turned off diff --git a/test_unit/test_signal.cpp b/test_unit/test_signal.cpp new file mode 100644 index 0000000..0d92087 --- /dev/null +++ b/test_unit/test_signal.cpp @@ -0,0 +1,62 @@ +#include +#include "g3log/crashhandler.hpp" + +#if !(defined(WIN32) || defined(_WIN32) || defined(__WIN32__)) +#include +#include + +class SignalHandlingTest : public ::testing::Test { + protected: + int original_stderr; + int pipefd[2]; + FILE* temp_stderr; + + void SetUp() override { + // Redirect stderr to a pipe + ASSERT_EQ(pipe(pipefd), 0); + original_stderr = dup(STDERR_FILENO); + ASSERT_NE(original_stderr, -1); + ASSERT_NE(dup2(pipefd[1], STDERR_FILENO), -1); + temp_stderr = fdopen(pipefd[1], "w"); + setvbuf(temp_stderr, NULL, _IONBF, 0); // Disable buffering + + // Set the read end of the pipe to non-blocking mode + // so we can verify when buffer is empty + int flags = fcntl(pipefd[0], F_GETFL, 0); + fcntl(pipefd[0], F_SETFL, flags | O_NONBLOCK); + } + + void TearDown() override { + // Restore the original stderr + fclose(temp_stderr); + close(pipefd[0]); + close(pipefd[1]); + dup2(original_stderr, STDERR_FILENO); + close(original_stderr); + } + + std::string ReadStderr() { + char buffer[1024]; + ssize_t bytes_read = read(pipefd[0], buffer, sizeof(buffer) - 1); + if (bytes_read >= 0) { + buffer[bytes_read] = '\0'; // Null-terminate the string + return std::string(buffer); + } + return ""; + } +}; + +TEST_F(SignalHandlingTest, WriteErrorMessage_WritesToStderr) { + const char* test_message = "Test error message"; + g3::internal::writeErrorMessage(test_message); + std::string output = ReadStderr(); + ASSERT_EQ(output, test_message); +} + +TEST_F(SignalHandlingTest, WriteErrorMessage_Nullptr_DoesNotWriteToStderr) { + g3::internal::writeErrorMessage(nullptr); + std::string output = ReadStderr(); + ASSERT_TRUE(output.empty()); +} + +#endif // #if !(defined(WIN32) || defined(_WIN32) || defined(__WIN32__)) \ No newline at end of file