Updated. LOG(...) calls to uninizialized logger does not make it crash

This commit is contained in:
KjellKod 2013-11-07 01:56:48 -07:00
parent 99ea2e3f19
commit ad322fd460
11 changed files with 398 additions and 226 deletions

View File

@ -134,8 +134,6 @@ namespace g2 {
// Triggered by g2log->g2LogWorker after receiving a FATAL trigger
// which is LOG(FATAL), CHECK(false) or a fatal signal our signalhandler caught.
// --- If LOG(FATAL) or CHECK(false) the signal_number will be SIGABRT
void exitWithDefaultSignalHandler(int signal_number) {
std::cerr << "Exiting - FATAL SIGNAL: " << signal_number << " " << std::flush;
struct sigaction action;

View File

@ -23,11 +23,12 @@ namespace g2 {
}
LogMessageBuilder::~LogMessageBuilder() {
LogMessage log_entry(_message);
if (log_entry.wasFatal()) {
FatalMessageBuilder trigger({log_entry.toString(), SIGABRT});
if (internal::wasFatal(_message->_level)) {
FatalMessageBuilder trigger({_message, SIGABRT});
return; // FatalMessageBuilder will send to worker at scope exit
}
LogMessage log_entry(_message);
internal::saveMessage(log_entry); // message saved to g2LogWorker
}
@ -62,16 +63,22 @@ namespace g2 {
/// FatalMessageBuilder
FatalMessageBuilder::FatalMessageBuilder(const std::string& exit_message, int fatal_signal)
: _exit_message(exit_message), _fatal_signal(fatal_signal) {
}
FatalMessageBuilder::FatalMessageBuilder(const std::string& exit_message, int signal_id)
: _fatal_message(std::make_shared<LogMessageImpl>(exit_message)), _fatal_signal(signal_id)
{ }
FatalMessageBuilder:: FatalMessageBuilder(std::shared_ptr<LogMessageImpl> details, int signal_id)
: _fatal_message(details), _fatal_signal(signal_id)
{}
FatalMessageBuilder::~FatalMessageBuilder() {
// 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
//..... OR it's in unit-test mode then we throw a std::runtime_error (and never hit sleep)
FatalMessage msg(_exit_message, _fatal_signal);
FatalMessage msg(_fatal_message, _fatal_signal);
//internal::fatalCall({_exit_message, _fatal_signal});
internal::fatalCall(msg);

View File

@ -21,9 +21,10 @@ namespace g2 {
struct FatalMessageBuilder {
//explicit FatalMessageBuilder(const FatalMessage& exit_message);
FatalMessageBuilder(const std::string& exit_message, int fatal_signal);
FatalMessageBuilder(std::shared_ptr<LogMessageImpl> details, int signal_id);
virtual ~FatalMessageBuilder();
std::string _exit_message;
std::shared_ptr<LogMessageImpl> _fatal_message;
int _fatal_signal;
};

View File

@ -72,12 +72,15 @@ namespace g2 {
* This is kept for test reasons and should normally not be used */
g2LogWorker* shutDownLogging();
/** FOR TESTING PURPOSES: @ref g2log.ipp
* By default the g2log will call g2LogWorker::fatal(...) which will
/** 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 */
void changeFatalInitHandlerForUnitTesting();
* 'fatal call' which can be done here
*
* The bool return values in the fatal_call is whether or not the fatal_call should
*
*/
void changeFatalInitHandlerForUnitTesting(std::function<void(FatalMessage) > fatal_call);
} // g2::internal
} // g2
@ -89,7 +92,7 @@ namespace g2 {
#define INTERNAL_CONTRACT_MESSAGE(boolean_expression) \
g2::LogMessageBuilder(__FILE__, __LINE__, __PRETTY_FUNCTION__, FATAL).setExpression(boolean_expression)
g2::LogMessageBuilder(__FILE__, __LINE__, __PRETTY_FUNCTION__, g2::internal::CONTRACT).setExpression(boolean_expression)
// LOG(level) is the API for the stream log

View File

@ -12,6 +12,7 @@
#include "g2logworker.hpp"
#include "g2logmessageimpl.hpp"
#include "g2loglevels.hpp"
#include "crashhandler.hpp"
#include <cassert>
#include <memory>
@ -57,37 +58,48 @@ namespace g2 {
g_logger_instance->save(log_entry);
}
/** Fatal call saved to logger. This will trigger SIGABRT or other fatal signal
* to exit the program. After saving the fatal message the calling thread
* will sleep forever (i.e. until the background thread catches up, saves the fatal
* message and kills the software with the fatal signal.
*/
void fatalCallToLogger(FatalMessage message) {
// real fatal call to loggr
internal::g_logger_instance->fatal(message);
}
if (!internal::isLoggingInitialized()) {
std::ostringstream error;
error << "FATAL CALL but logger is NOT initialized\n"
<< "SIGNAL: " << g2::internal::signalName(message.signal_id_)
<< "\nMessage: \n" << message.toString() << std::flush;
std::cerr << error;
internal::exitWithDefaultSignalHandler(message.signal_id_);
}
// By default this function pointer goes to \ref fatalCall;
void (*g_fatal_to_g2logworker_function_ptr)(FatalMessage) = fatalCallToLogger;
g_logger_instance->fatal(message);
void fatalCallForUnitTest(FatalMessage fatal_message) {
// mock fatal call, not to logger: used by unit test
assert(internal::g_logger_instance != nullptr);
internal::g_logger_instance->save(fatal_message.copyToLogMessage()); // calling 'save' instead of 'fatal'
throw std::runtime_error(fatal_message.toString());
}
/** The default, initial, handling to send a 'fatal' event to g2logworker
* he caller will stay here, eternally, until the software is aborted
* During unit testing the sleep-loop will be interrupted by exception from
* @ref fatalCallForUnitTest */
void fatalCall(FatalMessage message) {
g_fatal_to_g2logworker_function_ptr(message);
while (true) {
std::this_thread::sleep_for(std::chrono::seconds(1));
}
}
/** Used to REPLACE fatalCallToLogger for fatalCallForUnitTest
* This function switches the function pointer so that only
* 'unitTest' mock-fatal calls are made. */
void changeFatalInitHandlerForUnitTesting() {
g_fatal_to_g2logworker_function_ptr = fatalCallForUnitTest;
// By default this function pointer goes to \ref fatalCallToLogger;
std::function<void(FatalMessage) > g_fatal_to_g2logworker_function_ptr = fatalCallToLogger;
/** The default, initial, handling to send a 'fatal' event to g2logworker
* the caller will stay here, eternally, until the software is aborted
* ... in the case of unit testing it is the given "Mock" fatalCall that will
* define the behaviour.
*/
void fatalCall(FatalMessage message) {
g_fatal_to_g2logworker_function_ptr(message);
}
// REPLACE fatalCallToLogger for fatalCallForUnitTest
// This function switches the function pointer so that only
// 'unitTest' mock-fatal calls are made.
void changeFatalInitHandlerForUnitTesting(std::function<void(FatalMessage) > fatal_call) {
g_fatal_to_g2logworker_function_ptr = fatal_call;
}
} // internal
} // g2

View File

@ -66,13 +66,6 @@ namespace g2 {
return internal::wasFatal(_pimpl->_level);
}
// YYYY/MM/DD HH:MM:SS -- ref g2time.hpp/cpp
//out << "\n" << localtime_formatted(system_time, date_formatted);
//out << " " << localtime_formatted(system_time, time_formatted); // TODO: time kommer från LogEntry
//out << "." << std::chrono::duration_cast<std::chrono::microseconds>(steady_time - _steady_start_time).count();
//out << "\t" << message << std::flush;
std::string LogMessage::toString() const {
std::ostringstream oss;
oss << "\n" << timestamp() << "." << microseconds() << "\t";
@ -123,16 +116,12 @@ namespace g2 {
: _pimpl(details) { }
FatalMessage::FatalMessage(const std::string& crash_message, int signal_id)
: LogMessage(std::make_shared<LogMessageImpl>(crash_message)), signal_id_(signal_id)
{ }
FatalMessage::FatalMessage(std::shared_ptr<LogMessageImpl> details, int signal_id)
: LogMessage(details), signal_id_(signal_id) { }
LogMessage FatalMessage::copyToLogMessage() const {
return LogMessage(_pimpl);
}
//FatalMessage(const LogMessage& message, int signal_id)
//: _crash_message(message), signal_id_(signal_id) { }
} // g2

View File

@ -53,13 +53,11 @@ namespace g2 {
* A thread that causes a FatalMessage will sleep forever until the
* application has exited (after message flush) */
struct FatalMessage : public LogMessage {
FatalMessage(const std::string& message, int signal_id);
//FatalMessage(const LogMessage& message, int signal_id);
~FatalMessage() = default;
FatalMessage(std::shared_ptr<LogMessageImpl> details, int signal_id);
~FatalMessage() = default;
LogMessage copyToLogMessage() const;
//mutable LogMessage _crash_message;
int signal_id_;
};
} // g2

View File

@ -52,8 +52,7 @@ struct g2LogWorkerImpl {
}
void bgFatal(FatalMessage msg) {
//auto entry = fatal_message._crash_message;
auto fatal_message = msg;
auto fatal_message = msg;
fatal_message.stream() << "\nExiting after fatal event. Log flushed sucessfully to disk.\n";
bgSave(fatal_message.copyToLogMessage());

View File

@ -11,7 +11,6 @@
#include <memory>
#include <string>
#include <fstream>
#include <cstdio>
#include <thread>
#include <chrono>
@ -19,26 +18,6 @@
namespace {
const int k_wait_time = 5; // 5s wait between LOG/CHECK FATAL till we say it's too long time
const std::string log_directory = "./";
bool verifyContent(const std::string &total_text, std::string msg_to_find) {
std::string content(total_text);
size_t location = content.find(msg_to_find);
return (location != std::string::npos);
}
std::string readFileToText(std::string filename) {
std::ifstream in;
in.open(filename.c_str(), std::ios_base::in);
if (!in.is_open()) {
return
{ }; // error just return empty string - test will 'fault'
}
std::ostringstream oss;
oss << in.rdbuf();
return oss.str();
}
} // end anonymous namespace
@ -58,17 +37,64 @@ TEST(IO_RestoreFileLogger, Expecting_Fine_To_ShutDownMultipleTimes) {
}
}
/// THIS MUST BE THE FIRST UNIT TEST TO RUN! If any unit test run before this
/// one then it will fail
TEST(Initialization, No_Logger_Initialized___Expecting_LOG_calls_to_be_Still_OKish) {
{
// Temporarily enable all levels. then go out of scope again.
RestoreFileLogger logger(log_directory);
EXPECT_TRUE(g2::internal::isLoggingInitialized());
EXPECT_TRUE(g2::logLevel(INFO));
EXPECT_TRUE(g2::logLevel(FATAL));
EXPECT_TRUE(g2::logLevel(DEBUG));
EXPECT_TRUE(g2::logLevel(WARNING));
}
EXPECT_FALSE(g2::internal::isLoggingInitialized());
EXPECT_TRUE(g2::logLevel(INFO));
EXPECT_TRUE(g2::logLevel(FATAL));
EXPECT_TRUE(g2::logLevel(DEBUG));
EXPECT_TRUE(g2::logLevel(WARNING));
std::string err_msg1 = "Hey. I am not instantiated but I still should not crash. (I am g2logger)";
std::string err_msg2_ignored = "This uninitialized message should be ignored";
try {
LOG(INFO) << err_msg1;
LOG(INFO) << err_msg2_ignored;
} catch (std::exception& e) {
ADD_FAILURE() << "Should never have thrown even if it is not instantiated";
}
RestoreFileLogger logger(log_directory); // now instantiate the logger
auto content = logger.contentSoFar();
ASSERT_FALSE(verifyContent(content, err_msg1)) << "Content: [" << content << "]";
std::string good_msg1 = "This message will pull in also the uninitialized_call message";
LOG(INFO) << good_msg1;
content = logger.contentSoFar(); // this synchronizes with the LOG(INFO) call.
ASSERT_TRUE(verifyContent(content, err_msg1)) << "Content: [" << content << "]";
ASSERT_FALSE(verifyContent(content, err_msg2_ignored)) << "Content: [" << content << "]";
ASSERT_TRUE(verifyContent(content, good_msg1)) << "Content: [" << content << "]";
// debug this. it SHOULD crash since we havent fixed the code yet
}
TEST(LOGTest, LOG) {
std::string file_content;
{
RestoreFileLogger logger(log_directory);
EXPECT_TRUE(g2::logLevel(INFO));
EXPECT_TRUE(g2::logLevel(FATAL));
LOG(INFO) << "test LOG(INFO)";
logger.reset(); // force flush of logger
file_content = readFileToText(logger.logFile());
SCOPED_TRACE("LOG_INFO"); // Scope exit be prepared for destructor failure
}
ASSERT_TRUE(verifyContent(file_content, "test LOG(INFO)"));
EXPECT_TRUE(verifyContent(file_content, "test LOG(INFO)"));
EXPECT_TRUE(g2::logLevel(INFO));
EXPECT_TRUE(g2::logLevel(FATAL));
}
@ -106,8 +132,6 @@ TEST(LogTest, LOG_F) {
// stream-type log
TEST(LogTest, LOG) {
std::string file_content;
{
@ -150,125 +174,90 @@ TEST(LogTest, LOG_IF) {
file_content = readFileToText(logger.logFile());
SCOPED_TRACE("LOG_IF"); // Scope exit be prepared for destructor failure
}
ASSERT_TRUE(verifyContent(file_content, t_info2));
ASSERT_FALSE(verifyContent(file_content, t_debug2));
EXPECT_TRUE(verifyContent(file_content, t_info2));
EXPECT_FALSE(verifyContent(file_content, t_debug2));
}
TEST(LogTest, LOGF__FATAL) {
RestoreFileLogger logger(log_directory);
try {
LOGF(FATAL, "This message should throw %d", 0);
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
std::cerr << file_content << std::endl << std::flush;
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, "This message should throw")) {
SUCCEED();
return;
} else {
ADD_FAILURE() << "Didn't throw exception as expected";
}
}
ADD_FAILURE() << "Didn't throw exception at ALL";
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"));
EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL"));
logger.reset();
std::string file_content = readFileToText(logger.logFile());
EXPECT_TRUE(verifyContent(file_content, "This message should throw 0"));
EXPECT_TRUE(verifyContent(file_content, "FATAL"));
}
TEST(LogTest, LOG_FATAL) {
RestoreFileLogger logger(log_directory);
try {
LOG(FATAL) << "This message should throw";
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, "This message should throw")) {
SUCCEED();
return;
} else {
ADD_FAILURE() << "Didn't throw exception as expected";
}
}
ADD_FAILURE() << "Didn't throw exception at ALL";
ASSERT_FALSE(mockFatalWasCalled());
LOG(FATAL) << "This message should throw";
EXPECT_TRUE(mockFatalWasCalled());
EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by "));
EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw"))
<< "\ncontent: [[" << mockFatalMessage() << "]]";
EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL"));
logger.reset();
std::string file_content = readFileToText(logger.logFile());
EXPECT_TRUE(verifyContent(file_content, "This message should throw"));
EXPECT_TRUE(verifyContent(file_content, "FATAL"));
EXPECT_TRUE(verifyContent(file_content, "EXIT trigger caused by "));
}
TEST(LogTest, LOGF_IF__FATAL) {
RestoreFileLogger logger(log_directory);
try {
LOGF_IF(FATAL, (2 < 3), "This message%sshould throw", " ");
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, "This message should throw")) {
SUCCEED();
return;
} else {
ADD_FAILURE() << "Didn't throw exception as expected";
}
}
ADD_FAILURE() << "Didn't throw exception at ALL";
LOGF_IF(FATAL, (2 < 3), "This message%sshould throw", " ");
EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by "));
EXPECT_TRUE(verifyContent(mockFatalMessage(), "FATAL"));
EXPECT_TRUE(verifyContent(mockFatalMessage(), "This message should throw"));
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"));
}
TEST(LogTest, LOG_IF__FATAL) {
RestoreFileLogger logger(log_directory);
try {
LOG_IF(WARNING, (0 != t_info.compare(t_info))) << "This message should NOT be written";
LOG_IF(FATAL, (0 != t_info.compare(t_info2))) << "This message should throw";
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, "This message should throw") &&
(false == verifyContent(file_content, "This message should NOT be written"))) {
SUCCEED();
return;
} else {
ADD_FAILURE() << "Didn't throw exception as expected";
}
}
ADD_FAILURE() << "Didn't throw exception at ALL";
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);
try {
LOG_IF(FATAL, (2 > 3)) << "This message%sshould NOT throw";
} catch (std::exception const &e) {
std::cerr << e.what() << std::endl;
logger.reset();
ADD_FAILURE() << "Didn't throw exception as expected";
}
logger.reset();
SUCCEED();
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);
try {
CHECK(1 == 2);
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL")) {
SUCCEED();
return;
}
}
ADD_FAILURE() << "Didn't throw exception as expected";
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, "FATAL"));
}
@ -278,19 +267,12 @@ TEST(CHECK_F_Test, CHECK_F__thisWILL_PrintErrorMsg) {
std::string msg2 = "This message is added to throw message and log";
std::string arg1 = "message";
std::string arg2 = "log";
try {
//CHECK_F(1 >= 2, msg.c_str(), arg1.c_str(), arg2.c_str());
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, msg2)) {
SUCCEED();
return;
}
}
ADD_FAILURE() << "Didn't throw exception as expected";
CHECK_F(1 >= 2, msg.c_str(), arg1.c_str(), arg2.c_str());
logger.reset();
std::string file_content = readFileToText(logger.logFile());
EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by "));
EXPECT_TRUE(verifyContent(file_content, "FATAL"));
}
@ -300,37 +282,159 @@ TEST(CHECK_Test, CHECK__thisWILL_PrintErrorMsg) {
std::string msg2 = "This message is added to throw message and log";
std::string arg1 = "message";
std::string arg2 = "log";
try {
CHECK(1 >= 2) << msg2;
} catch (std::exception const &e) {
logger.reset();
std::string file_content = readFileToText(logger.logFile());
if (verifyContent(e.what(), "EXIT trigger caused by ") &&
verifyContent(file_content, "FATAL") &&
verifyContent(file_content, msg2)) {
SUCCEED();
return;
}
}
ADD_FAILURE() << "Didn't throw exception as expected";
CHECK(1 >= 2) << msg2;
logger.reset();
std::string file_content = readFileToText(logger.logFile());
EXPECT_TRUE(verifyContent(mockFatalMessage(), "EXIT trigger caused by "));
EXPECT_TRUE(verifyContent(file_content, "FATAL"));
EXPECT_TRUE(verifyContent(file_content, msg2));
}
TEST(CHECK, CHECK_ThatWontThrow) {
RestoreFileLogger logger(log_directory);
std::string msg = "This %s should never appear in the %s";
std::string msg2 = "This message should never appear in the log";
std::string arg1 = "message";
std::string arg2 = "log";
CHECK(1 == 1);
CHECK_F(1 == 1, msg.c_str(), "message", "log");
EXPECT_FALSE(mockFatalWasCalled());
std::string file_content = readFileToText(logger.logFile());
EXPECT_FALSE(verifyContent(file_content, msg2));
EXPECT_FALSE(verifyContent(mockFatalMessage(), msg2));
}
#ifdef G2_DYNAMIC_LOGGING
namespace {
// Restore dynamic levels if turned off
struct RestoreDynamicLoggingLevels {
RestoreDynamicLoggingLevels() {
};
~RestoreDynamicLoggingLevels() {
g2::setLogLevel(DEBUG, false);
g2::setLogLevel(INFO, false);
g2::setLogLevel(WARNING, false);
g2::setLogLevel(FATAL, false);
}
};
} // anonymous
TEST(DynamicLogging, DynamicLogging_IS_ENABLED) {
RestoreDynamicLoggingLevels raiiLevelRestore;
ASSERT_TRUE(g2::logLevel(DEBUG));
ASSERT_TRUE(g2::logLevel(INFO));
ASSERT_TRUE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL)); // Yes FATAL can be turned off. Thereby rendering it ineffective.
g2::setLogLevel(DEBUG, false);
ASSERT_FALSE(g2::logLevel(DEBUG));
ASSERT_TRUE(g2::logLevel(INFO));
ASSERT_TRUE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL)); // Yes FATAL can be turned off. Thereby rendering it ineffective.
g2::setLogLevel(INFO, false);
ASSERT_FALSE(g2::logLevel(DEBUG));
ASSERT_FALSE(g2::logLevel(INFO));
ASSERT_TRUE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL)); // Yes FATAL can be turned off. Thereby rendering it ineffective.
g2::setLogLevel(WARNING, false);
ASSERT_FALSE(g2::logLevel(DEBUG));
ASSERT_FALSE(g2::logLevel(INFO));
ASSERT_FALSE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL)); // Yes FATAL can be turned off. Thereby rendering it ineffective.
g2::setLogLevel(FATAL, false);
ASSERT_FALSE(g2::logLevel(DEBUG));
ASSERT_FALSE(g2::logLevel(INFO));
ASSERT_FALSE(g2::logLevel(WARNING));
ASSERT_FALSE(g2::logLevel(FATAL)); // Yes FATAL can be turned off. Thereby rendering it ineffective.
}
TEST(DynamicLogging, DynamicLogging_No_Logs_If_Disabled) {
RestoreFileLogger logger(log_directory);
ASSERT_TRUE(g2::logLevel(DEBUG));
ASSERT_TRUE(g2::logLevel(INFO));
ASSERT_TRUE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL));
RestoreDynamicLoggingLevels raiiLevelRestore;
std::string msg_debugOn = "This %s SHOULD appear in the %s";
std::string msg_debugOff = "This message should never appear in the log";
std::string msg_info1 = "This info msg log";
try {
CHECK(1 == 1);
CHECK_F(1 == 1, msg.c_str(), "message", "log");
LOGF(DEBUG, msg_debugOn.c_str(), "msg", "log");
auto content = logger.contentSoFar();
ASSERT_TRUE(verifyContent(content, "This msg SHOULD appear in the log")) << "Content: [" << content << "]";
g2::setLogLevel(DEBUG, false);
EXPECT_FALSE(g2::logLevel(DEBUG));
LOG(DEBUG) << msg_debugOff;
content = logger.contentSoFar();
ASSERT_FALSE(verifyContent(content, "This message should never appear in the log")) << "Content: [" << content << "]";
} catch (std::exception const &e) {
std::cerr << e.what() << std::endl;
ADD_FAILURE() << "Should never have thrown";
}
}
TEST(DynamicLogging, DynamicLogging_No_Fatal_If_Disabled) {
RestoreFileLogger logger(log_directory);
RestoreDynamicLoggingLevels raiiLevelRestore;
ASSERT_TRUE(g2::logLevel(DEBUG));
ASSERT_TRUE(g2::logLevel(INFO));
ASSERT_TRUE(g2::logLevel(WARNING));
ASSERT_TRUE(g2::logLevel(FATAL));
std::string file_content = readFileToText(logger.logFile());
ASSERT_FALSE(verifyContent(file_content, msg2));
std::string msg1 = "This IS fatal (not crash, since it is unit test";
LOG(FATAL) << msg1;
EXPECT_TRUE(mockFatalWasCalled());
EXPECT_FALSE(mockFatalMessage().empty());
EXPECT_TRUE(verifyContent(mockFatalMessage(), msg1));
clearMockFatal();
EXPECT_FALSE(mockFatalWasCalled());
g2::setLogLevel(FATAL, false);
std::string msg2 = "This is NOT fatal (not crash, since it is unit test. FATAL is disabled";
LOG(FATAL) << msg2;
EXPECT_FALSE(mockFatalWasCalled());
EXPECT_TRUE(mockFatalMessage().empty());
}
TEST(DynamicLogging, DynamicLogging_Check_WillAlsoBeTurnedOffWhen_Fatal_Is_Disabled) {
RestoreFileLogger logger(log_directory);
RestoreDynamicLoggingLevels raiiLevelRestore;
ASSERT_TRUE(g2::logLevel(FATAL));
std::string msg1 = "dummy message to check if CHECK worked when fatal is enabled";
std::string msg2 = "dummy message to check if CHECK worked when fatal is disabled";
LOG(FATAL) << msg1;
EXPECT_TRUE(mockFatalWasCalled());
EXPECT_TRUE(verifyContent(mockFatalMessage(), msg1));
clearMockFatal();
EXPECT_FALSE(mockFatalWasCalled());
// Disable also CHECK calls
g2::setLogLevel(FATAL, false);
ASSERT_FALSE(g2::logLevel(FATAL));
LOG(FATAL) << msg2;
EXPECT_FALSE(mockFatalWasCalled());
}
#else
TEST(DynamicLogging, DynamicLogging_IS_NOT_ENABLED) {
ASSERT_TRUE(g2::logLevel(DEBUG));
//g2::setLogLevel(DEBUG, false); this line will not compile since G2_DYNAMIC_LOGGING is not enabled. Kept for show.
//ASSERT_FALSE(g2::logLevel(DEBUG));
}
#endif // Dynamic logging

View File

@ -4,17 +4,56 @@
#include "testing_helpers.h"
#include "g2log.hpp"
#include "g2logworker.hpp"
#include "g2filesink.hpp"
#include "std2_make_unique.hpp"
#include <fstream>
using namespace std;
namespace testing_helpers {
std::string g_mockFatal_message = {};
int g_mockFatal_signal = -1;
bool g_mockFatalWasCalled = false;
std::string mockFatalMessage() { return g_mockFatal_message; }
int mockFatalSignal() { return g_mockFatal_signal; }
bool mockFatalWasCalled() { return g_mockFatalWasCalled; }
void mockFatalCall(g2::FatalMessage fatal_message) {
g_mockFatal_message = fatal_message.toString();
g_mockFatal_signal = fatal_message.signal_id_;
g_mockFatalWasCalled = true;
}
void clearMockFatal() {
g_mockFatal_message = {};
g_mockFatal_signal = -1;
g_mockFatalWasCalled = false;
}
bool removeFile(std::string path_to_file) {
return (0 == std::remove(path_to_file.c_str()));
}
bool verifyContent(const std::string &total_text, std::string msg_to_find) {
std::string content(total_text);
size_t location = content.find(msg_to_find);
return (location != std::string::npos);
}
std::string readFileToText(std::string filename) {
std::ifstream in;
in.open(filename.c_str(), std::ios_base::in);
if (!in.is_open()) {
return
{
}; // error just return empty string - test will 'fault'
}
std::ostringstream oss;
oss << in.rdbuf();
return oss.str();
}
size_t LogFileCleaner::size() {
return logs_to_clean_.size();
}
@ -61,24 +100,31 @@ namespace testing_helpers {
RestoreFileLogger::RestoreFileLogger(std::string directory)
: scope_(new ScopedLogger)
: _scope(new ScopedLogger), _handle(_scope->get()->addSink(std2::make_unique<g2::FileSink>("UNIT_TEST_LOGGER", directory), &g2::FileSink::fileWrite))
{
using namespace g2;
auto filehandler = scope_->get()->addSink(std2::make_unique<FileSink>("UNIT_TEST_LOGGER", directory), &FileSink::fileWrite);
internal::changeFatalInitHandlerForUnitTesting(&mockFatalCall);
internal::changeFatalInitHandlerForUnitTesting();
LOG(INFO) << "Restore logger test ";
auto filename = filehandler->call(&FileSink::fileName);
auto filename = _handle->call(&FileSink::fileName);
if (!filename.valid()) ADD_FAILURE();
log_file_ = filename.get();
_log_file = filename.get();
}
RestoreFileLogger::~RestoreFileLogger() {
scope_.reset();
if (!removeFile(log_file_))
_scope.reset();
if (!removeFile(_log_file))
ADD_FAILURE();
}
std::string RestoreFileLogger::contentSoFar() {
std::future<std::string> filename = _handle->call(&g2::FileSink::fileName);
EXPECT_TRUE(filename.valid());
auto file = filename.get();
return readFileToText(file);
}

View File

@ -15,10 +15,21 @@
#include <algorithm>
#include "g2logworker.hpp"
#include "g2logmessage.hpp"
#include "g2filesink.hpp"
namespace testing_helpers {
std::string mockFatalMessage();
int mockFatalSignal();
bool mockFatalWasCalled();
void mockFatalCall(g2::FatalMessage fatal_message);
void clearMockFatal();
bool removeFile(std::string path_to_file);
bool verifyContent(const std::string &total_text, std::string msg_to_find);
std::string readFileToText(std::string filename);
/** After initializing ScopedCout all std::couts is redirected to the buffer
@verbatim
@ -79,19 +90,23 @@ struct RestoreFileLogger {
explicit RestoreFileLogger(std::string directory);
~RestoreFileLogger();
std::unique_ptr<ScopedLogger> scope_;
void reset(){ scope_.reset();}
std::unique_ptr<ScopedLogger> _scope;
void reset(){ _scope.reset();}
template<typename Call, typename ... Args >
typename std::result_of<Call(Args...)>::type callToLogger(Call call, Args&&... args) {
auto func = std::bind(call, scope_->get(), std::forward<Args>(args)...);
auto func = std::bind(call, _scope->get(), std::forward<Args>(args)...);
return func();
}
std::string logFile() { return log_file_; }
std::string logFile() { return _log_file; }
std::string contentSoFar();
private:
std::string log_file_;
std::unique_ptr<g2::SinkHandle<g2::FileSink>> _handle;
std::string _log_file;
};