From d9d2945d6189991d001ff7000dfb93798b91c1da Mon Sep 17 00:00:00 2001 From: Eran Date: Wed, 29 May 2024 09:38:54 +0300 Subject: [PATCH] disable unused EL++ log levels for performance --- src/log.h | 64 +++++++++++++++------------ unit-tests/log/test-vs-LOG-static.cpp | 27 +++++++++-- 2 files changed, 58 insertions(+), 33 deletions(-) diff --git a/src/log.h b/src/log.h index 979d6f5506..6fb9f5295b 100644 --- a/src/log.h +++ b/src/log.h @@ -55,9 +55,9 @@ namespace librealsense template class logger_type { - rs2_log_severity minimum_log_severity = RS2_LOG_SEVERITY_NONE; rs2_log_severity minimum_console_severity = RS2_LOG_SEVERITY_NONE; rs2_log_severity minimum_file_severity = RS2_LOG_SEVERITY_NONE; + rs2_log_severity minimum_callback_severity = RS2_LOG_SEVERITY_NONE; std::mutex log_mutex; std::ofstream log_file; @@ -104,16 +104,12 @@ namespace librealsense defaultConf.setToDefault(); // To set GLOBAL configurations you may use - defaultConf.setGlobally(el::ConfigurationType::ToFile, "false"); - defaultConf.setGlobally(el::ConfigurationType::ToStandardOutput, "false"); - defaultConf.setGlobally(el::ConfigurationType::LogFlushThreshold, "10"); - defaultConf.setGlobally(el::ConfigurationType::Format, " %datetime{%d/%M %H:%m:%s,%g} %level [%thread] (%fbase:%line) %msg"); - - for (int i = minimum_console_severity; i < RS2_LOG_SEVERITY_NONE; i++) - { - defaultConf.set(severity_to_level(static_cast(i)), - el::ConfigurationType::ToStandardOutput, "true"); - } + defaultConf.setGlobally( el::ConfigurationType::Enabled, "false" ); + defaultConf.setGlobally( el::ConfigurationType::ToFile, "false" ); + defaultConf.setGlobally( el::ConfigurationType::ToStandardOutput, "false" ); + defaultConf.setGlobally( el::ConfigurationType::LogFlushThreshold, "10" ); + defaultConf.setGlobally( el::ConfigurationType::Format, + " %datetime{%d/%M %H:%m:%s,%g} %level [%thread] (%fbase:%line) %msg" ); // NOTE: you can only log to one file, so successive calls to log_to_file // will override one another! @@ -123,10 +119,21 @@ namespace librealsense // prevents creation of empty log files that are not required. defaultConf.setGlobally(el::ConfigurationType::Filename, filename); } - for (int i = minimum_file_severity; i < RS2_LOG_SEVERITY_NONE; i++) + + auto min_severity + = std::min( minimum_file_severity, std::min( minimum_callback_severity, minimum_console_severity ) ); + + for( int i = RS2_LOG_SEVERITY_DEBUG; i < RS2_LOG_SEVERITY_NONE; ++i ) { - defaultConf.set(severity_to_level(static_cast(i)), - el::ConfigurationType::ToFile, "true"); + auto severity = static_cast< rs2_log_severity >( i ); + auto level = severity_to_level( severity ); + defaultConf.set( level, el::ConfigurationType::Enabled, severity >= min_severity ? "true" : "false" ); + defaultConf.set( level, + el::ConfigurationType::ToStandardOutput, + severity >= minimum_console_severity ? "true" : "false" ); + defaultConf.set( level, + el::ConfigurationType::ToFile, + severity >= minimum_file_severity ? "true" : "false" ); } el::Loggers::reconfigureLogger(log_id, defaultConf); @@ -138,8 +145,9 @@ namespace librealsense defaultConf.setToDefault(); // To set GLOBAL configurations you may use - defaultConf.setGlobally(el::ConfigurationType::ToFile, "false"); - defaultConf.setGlobally(el::ConfigurationType::ToStandardOutput, "false"); + defaultConf.setGlobally( el::ConfigurationType::Enabled, "false" ); + defaultConf.setGlobally( el::ConfigurationType::ToFile, "false" ); + defaultConf.setGlobally( el::ConfigurationType::ToStandardOutput, "false" ); el::Loggers::reconfigureLogger(log_id, defaultConf); } @@ -148,15 +156,10 @@ namespace librealsense logger_type() : filename( rsutils::string::from::datetime() + ".log" ) { - rs2_log_severity severity; - if (try_get_log_severity(severity)) - { - log_to_file(severity, filename.c_str()); - } + if( try_get_log_severity( minimum_file_severity ) ) + open(); else - { open_def(); - } } static bool try_get_log_severity(rs2_log_severity& severity) @@ -233,12 +236,11 @@ namespace librealsense for( auto const& dispatch : callback_dispatchers ) el::Helpers::uninstallLogDispatchCallback< elpp_dispatcher >( dispatch ); callback_dispatchers.clear(); + minimum_callback_severity = RS2_LOG_SEVERITY_NONE; } void log_to_callback( rs2_log_severity min_severity, rs2_log_callback_sptr callback ) { - open(); - try_get_log_severity( min_severity ); if( callback && min_severity != RS2_LOG_SEVERITY_NONE ) { @@ -255,21 +257,25 @@ namespace librealsense auto dispatcher = el::Helpers::logDispatchCallback< elpp_dispatcher >( dispatch_name ); dispatcher->callback = callback; dispatcher->min_severity = min_severity; + if( min_severity < minimum_callback_severity ) + minimum_callback_severity = min_severity; // Remove the default logger (which will log to standard out/err) or it'll still be active //el::Helpers::uninstallLogDispatchCallback< el::base::DefaultLogDispatchCallback >( "DefaultLogDispatchCallback" ); + + open(); } } // Stop logging and reset logger to initial configurations void reset_logger() { - el::Loggers::reconfigureLogger(log_id, el::ConfigurationType::ToFile, "false"); - el::Loggers::reconfigureLogger(log_id, el::ConfigurationType::ToStandardOutput, "false"); - el::Loggers::reconfigureLogger(log_id, el::ConfigurationType::MaxLogFileSize, "0"); + el::Loggers::reconfigureLogger( log_id, el::ConfigurationType::Enabled, "false" ); + el::Loggers::reconfigureLogger( log_id, el::ConfigurationType::ToFile, "false" ); + el::Loggers::reconfigureLogger( log_id, el::ConfigurationType::ToStandardOutput, "false" ); + el::Loggers::reconfigureLogger( log_id, el::ConfigurationType::MaxLogFileSize, "0" ); remove_callbacks(); - minimum_log_severity = RS2_LOG_SEVERITY_NONE; minimum_console_severity = RS2_LOG_SEVERITY_NONE; minimum_file_severity = RS2_LOG_SEVERITY_NONE; } diff --git a/unit-tests/log/test-vs-LOG-static.cpp b/unit-tests/log/test-vs-LOG-static.cpp index 09be482252..f2142c32f6 100644 --- a/unit-tests/log/test-vs-LOG-static.cpp +++ b/unit-tests/log/test-vs-LOG-static.cpp @@ -23,6 +23,11 @@ using namespace librealsense; +static void dummy_callback( rs2_log_severity, rs2_log_message const *, void * ) +{ +}; + + TEST_CASE( "rs2_log vs LOG() - internal", "[log]" ) { size_t n_callbacks = 0; @@ -46,16 +51,30 @@ TEST_CASE( "rs2_log vs LOG() - internal", "[log]" ) // LOG(XXX) should log to the default logger, which is NOT the librealsense logger LOG(INFO) << "Log message to default logger"; - REQUIRE( n_callbacks == 1 ); + CHECK( n_callbacks == 1 ); + + // The librealsense logging mechanism is still off, so we don't get any callbacks + + CLOG( INFO, LIBREALSENSE_ELPP_ID ) << "Log message to \"librealsense\" logger"; + CHECK( n_callbacks == 1 ); + + LOG_INFO( "Log message using LOG_INFO()" ); + CHECK( n_callbacks == 1 ); + + REQUIRE_NOTHROW( rs2_log( RS2_LOG_SEVERITY_INFO, "Log message using rs2_log()", nullptr ) ); + CHECK( n_callbacks == 1 ); + + // But once we turn it on... + rs2_log_to_callback( RS2_LOG_SEVERITY_INFO, &dummy_callback, nullptr, nullptr ); CLOG(INFO, LIBREALSENSE_ELPP_ID) << "Log message to \"librealsense\" logger"; - REQUIRE( n_callbacks == 2 ); + CHECK( n_callbacks == 2 ); LOG_INFO( "Log message using LOG_INFO()" ); - REQUIRE( n_callbacks == 3 ); + CHECK( n_callbacks == 3 ); REQUIRE_NOTHROW( rs2_log( RS2_LOG_SEVERITY_INFO, "Log message using rs2_log()", nullptr )); - REQUIRE( n_callbacks == 4 ); + CHECK( n_callbacks == 4 ); // NOTE that all the above called the same callback!! Callbacks are not logger-specific! }