Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LRS_LOG_LEVEL fix; enable log optimizations #12978

Merged
merged 3 commits into from
May 29, 2024
Merged

LRS_LOG_LEVEL fix; enable log optimizations #12978

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
4f24c59
fix string::from::datetime() returning empty string
maloel May 29, 2024
d9d2945
disable unused EL++ log levels for performance
maloel May 29, 2024
7470105
fix the CI to look for logs in the right place
maloel May 29, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions .github/workflows/buildsCI.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -300,7 +300,7 @@ jobs:
uses: actions/upload-artifact@v3
with:
name: Log file - U22_ST_Py_EX_CfU_LiveTest
path: build/*.log
path: build/${{env.LRS_RUN_CONFIG}}/*.log

- name: Provide correct exit status for job
shell: bash
Expand Down Expand Up @@ -503,7 +503,7 @@ jobs:
uses: actions/upload-artifact@v3
with:
name: Log file - U22_SH_RSUSB_LiveTest
path: build/*.log
path: build/${{env.LRS_BUILD_CONFIG}}/*.log

- name: Provide correct exit status for job
shell: bash
Expand Down
64 changes: 35 additions & 29 deletions src/log.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -55,9 +55,9 @@ namespace librealsense
template<char const * NAME>
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;
Expand Down Expand Up @@ -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<rs2_log_severity>(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!
Expand All @@ -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<rs2_log_severity>(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);
Expand All @@ -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);
}
Expand All @@ -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)
Expand Down Expand Up @@ -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 )
{
Expand All @@ -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;
}
Expand Down
2 changes: 1 addition & 1 deletion third-party/rsutils/src/from.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ std::string from::datetime( tm const * time, char const * format )
std::string buffer;
if( time )
{
buffer.reserve( 50 );
buffer.resize( 50 );
size_t cch = strftime( const_cast< char * >( buffer.data() ), buffer.capacity(), format, time );
// "Provided that the result string, including the terminating null byte, does not exceed max bytes, strftime()
// returns the number of bytes (excluding the terminating null byte) placed in the array. If the length of the
Expand Down
27 changes: 23 additions & 4 deletions unit-tests/log/test-vs-LOG-static.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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!
}
Loading