dynamic logging levels are now possible. Use "#define G2_DYNAMIC_LOGGING" to get it. A slight performance penalty will result

but logging levels can then be turn on/off dynamically
This commit is contained in:
KjellKod 2013-12-10 14:57:04 -07:00
parent 340c4ac1d5
commit f8c729ce1e
5 changed files with 99 additions and 43 deletions

View File

@ -107,17 +107,31 @@ ENDIF(MSVC)
endif(MSVC)
set(SRC_FILES ${SRC_FILES} ${SRC_PLATFORM_SPECIFIC})
# Create the g2log library
include_directories(${LOG_SRC})
MESSAGE(" g2logger files: [${SRC_FILES}]")
add_library(lib_g2logger ${SRC_FILES})
set_target_properties(lib_g2logger PROPERTIES LINKER_LANGUAGE CXX)
MESSAGE(" g3logger files: [${SRC_FILES}]")
add_library(lib_g3logger ${SRC_FILES})
set_target_properties(lib_g3logger PROPERTIES LINKER_LANGUAGE CXX)
# ============================================================================
# OPTIONS: Turn OFF the ones that is of no interest to you
# G2LOG OPTIONS: Turn OFF the ones that is of no interest to you
# ============================================================================
option (USE_DYNAMIC_LOGGING_LEVELS
"Turn ON/OFF log levels. An disabled level will not push logs of that level to the sink. By default dynamic logging is disabled" OFF)
# Do 'cmake -DUSE_DYNAMIC_LOGGING_LEVELS=ON' to enable this
# (or change the default option above)
if(USE_DYNAMIC_LOGGING_LEVELS)
add_definitions(-DG2_DYNAMIC_LOGGING)
MESSAGE ("\nUSE_DYNAMIC_LOGGING_LEVELS is turned on"\n\t"Use g2::setLogLevel(LEVEL boolean) to enable/disable logging on specified levels.\n\tAll levels are by default turn ON\n\n")
endif(USE_DYNAMIC_LOGGING_LEVELS)
# ============================================================================
# TEST OPTIONS: Turn OFF the ones that is of no interest to you
# ---- by default all is OFF: except 'g2log-FATAL-example -----
# ---- the reason for this is that
# ----- 1) the performance tests were only thoroughly tested on Ubuntu, not windows-
@ -126,6 +140,7 @@ ENDIF(MSVC)
# 2) The unit test were tested windows/linux,. but must be unzipped
# before it can be "cmake'd" and compiled --- leaving it as OFF for now
# ============================================================================
# 1. a simple test example 'g2log-FATAL-example'
option (USE_SIMPLE_EXAMPLE "Simple (fatal-crash) example " ON)
@ -155,7 +170,7 @@ ENDIF(MSVC)
MESSAGE(" g2log-FATAL-example option ON")
include_directories (${DIR_EXAMPLE})
add_executable(g2log-FATAL-example ${DIR_EXAMPLE}/main.cpp)
target_link_libraries(g2log-FATAL-example lib_g2logger ${PLATFORM_LINK_LIBRIES})
target_link_libraries(g2log-FATAL-example lib_g3logger ${PLATFORM_LINK_LIBRIES})
endif (USE_SIMPLE_EXAMPLE)
@ -170,13 +185,13 @@ ENDIF(MSVC)
${DIR_PERFORMANCE}/main_threaded_mean.cpp ${DIR_PERFORMANCE}/performance.h)
# Turn on G2LOG performance flag
set_target_properties(g2log-performance-threaded_mean PROPERTIES COMPILE_DEFINITIONS "G2LOG_PERFORMANCE=1")
target_link_libraries(g2log-performance-threaded_mean lib_g2logger ${PLATFORM_LINK_LIBRIES})
target_link_libraries(g2log-performance-threaded_mean lib_g3logger ${PLATFORM_LINK_LIBRIES})
# WORST CASE PERFORMANCE TEST
add_executable(g2log-performance-threaded_worst ${DIR_PERFORMANCE}/main_threaded_worst.cpp ${DIR_PERFORMANCE}/performance.h)
# Turn on G2LOG performance flag
set_target_properties(g2log-performance-threaded_worst PROPERTIES COMPILE_DEFINITIONS "G2LOG_PERFORMANCE=1")
target_link_libraries(g2log-performance-threaded_worst lib_g2logger ${PLATFORM_LINK_LIBRIES})
target_link_libraries(g2log-performance-threaded_worst lib_g3logger ${PLATFORM_LINK_LIBRIES})
endif (USE_G2LOG_PERFORMANCE)
@ -244,13 +259,13 @@ ENDIF(MSVC)
set_target_properties(${test} PROPERTIES COMPILE_DEFINITIONS "_VARIADIC_MAX=10")
set_target_properties(${test} PROPERTIES COMPILE_DEFINITIONS "GTEST_USE_OWN_TR1_TUPLE=0")
target_link_libraries(${test} lib_g2logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
target_link_libraries(${test} lib_g3logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
ENDFOREACH(test)
#add_executable(test_ALL ${all_tests} ${DIR_UNIT_TEST}/test_filechange.cpp ${helper})
#set_target_properties(test_ALL PROPERTIES COMPILE_DEFINITIONS "_VARIADIC_MAX=10")
#set_target_properties(test_ALL PROPERTIES COMPILE_DEFINITIONS "GTEST_USE_OWN_TR1_TUPLE=0")
#target_link_libraries(test_ALL lib_g2logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
#target_link_libraries(test_ALL lib_g3logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
@ -262,7 +277,7 @@ ENDIF(MSVC)
#
# set_target_properties(${test_ALL} PROPERTIES COMPILE_DEFINITIONS "_VARIADIC_MAX=10")
# set_target_properties(${test_ALL} PROPERTIES COMPILE_DEFINITIONS "GTEST_USE_OWN_TR1_TUPLE=0")
# target_link_libraries(${test_ALL} lib_g2logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
# target_link_libraries(${test_ALL} lib_g3logger gtest_160_lib ${PLATFORM_LINK_LIBRIES})
endif (USE_G2LOG_UNIT_TEST)

View File

@ -10,9 +10,9 @@
* ********************************************* */
#include "g2loglevels.hpp"
#include "g2log.hpp"
#include <atomic>
namespace g2
{
namespace internal {
@ -20,7 +20,8 @@ namespace g2
return level.value > WARNING.value;
}
std::atomic<bool> g_log_level_status[4]; // DEBUG, INFO, WARNING, FATAL
// By default all are OFF. At instantiation they are turned on. DEBUG, INFO, WARNING, FATAL
std::atomic<bool> g_log_level_status[4];
} // internal
@ -33,7 +34,7 @@ namespace g2
}
#endif
bool logLevel(LEVELS log_level)
{
#ifdef G2_DYNAMIC_LOGGING

View File

@ -8,6 +8,7 @@
#include "g2log.hpp"
#include "g2logworker.hpp"
#include "testing_helpers.h"
#include "g2loglevels.hpp"
#include <memory>
#include <string>
@ -25,19 +26,37 @@ using namespace testing_helpers;
/// THIS MUST BE THE FIRST UNIT TEST TO RUN! If any unit test run before this
/// one then it will fail
/// one then it will fail. For dynamic levels all levels are turned on only AT
/// instantiation so we do different test for dynamic logging levels
#ifdef G2_DYNAMIC_LOGGING
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);
using namespace g2::internal;
EXPECT_TRUE(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_FALSE(g2::logLevel(INFO));
EXPECT_FALSE(g2::logLevel(FATAL));
EXPECT_FALSE(g2::logLevel(DEBUG));
EXPECT_FALSE(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; // nothing happened. level not ON
LOG(INFO) << err_msg2_ignored; // nothing happened. level not ON
} catch (std::exception& e) {
ADD_FAILURE() << "Should never have thrown even if it is not instantiated";
}
RestoreFileLogger logger(log_directory); // now instantiate the logger
std::string good_msg1 = "This message could have pulled in the uninitialized_call message";
LOG(INFO) << good_msg1;
auto content = logger.resetAndRetrieveContent(); // this synchronizes with the LOG(INFO) call if debug level would be ON.
ASSERT_FALSE(verifyContent(content, err_msg1)) << "Content: [" << content << "]";
ASSERT_FALSE(verifyContent(content, err_msg2_ignored)) << "Content: [" << content << "]";
ASSERT_TRUE(verifyContent(content, good_msg1)) << "Content: [" << content << "]";
}
#else
TEST(Initialization, No_Logger_Initialized___Expecting_LOG_calls_to_be_Still_OKish) {
EXPECT_FALSE(g2::internal::isLoggingInitialized());
EXPECT_TRUE(g2::logLevel(INFO));
EXPECT_TRUE(g2::logLevel(FATAL));
@ -62,9 +81,8 @@ TEST(Initialization, No_Logger_Initialized___Expecting_LOG_calls_to_be_Still_OKi
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
}
}
#endif // #ifdef G2_DYNAMIC_LOGGING
TEST(LOGTest, LOG) {
@ -341,28 +359,36 @@ TEST(DynamicLogging, DynamicLogging_IS_ENABLED) {
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));
{
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 {
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 << "]";
{
RestoreFileLogger logger(log_directory);
LOGF(DEBUG, msg_debugOn.c_str(), "msg", "log");
auto content = logger.resetAndRetrieveContent();
ASSERT_TRUE(verifyContent(content, "This msg SHOULD appear in the log")) << "Content: [" << content << "]";
}
{
RestoreFileLogger logger(log_directory);
g2::setLogLevel(DEBUG, false);
EXPECT_FALSE(g2::logLevel(DEBUG));
LOG(DEBUG) << msg_debugOff;
auto content = logger.resetAndRetrieveContent();
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";

View File

@ -128,6 +128,20 @@ namespace testing_helpers {
}
std::string RestoreFileLogger::logFile() {
if (_scope) {
// beware for race condition
// example:
// LOG(INFO) << ...
// auto file = logger.logFile()
// auto content = ReadContentFromFile(file)
// ... it is not guaranteed that the content will contain (yet) the LOG(INFO)
std::future<std::string> filename = _handle->call(&g2::FileSink::fileName);
_log_file = filename.get();
}
return _log_file;
}
// Beware of race between LOG(...) and this function.
// since LOG(...) passes two queues but the handle::call only passes one queue
// the handle::call can happen faster

View File

@ -99,7 +99,7 @@ struct RestoreFileLogger {
return func();
}
std::string logFile() { return _log_file; }
std::string logFile();
std::string resetAndRetrieveContent();