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

Fix FW logs bug. #12853

Merged
merged 3 commits into from
Apr 15, 2024
Merged

Fix FW logs bug. #12853

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
399c18a
Fix FW logs bug, did not parse logs returned for start command
OhadMeir Apr 15, 2024
8cd2376
Parse FW logs XML only once when starting to collect logs
OhadMeir Apr 15, 2024
e4f0782
fixup! Fix FW logs bug, did not parse logs returned for start command
OhadMeir Apr 15, 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
123 changes: 71 additions & 52 deletions common/output-model.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,58 +21,70 @@ void output_model::thread_loop()
{
while (!to_stop)
{
std::vector<rs2::device> dev_copy;
if( enable_firmware_logs )
{
std::lock_guard<std::mutex> lock(devices_mutex);
dev_copy = devices;
}
if (enable_firmware_logs)
for (auto&& dev : dev_copy)
// User activated FW logs. Parse XML file and start collecting logs.
std::vector<rs2::device> dev_copy;
{
std::lock_guard<std::mutex> lock(devices_mutex);
dev_copy = devices;
}
std::vector< std::pair< rs2::firmware_logger, bool > > loggers; // Logger and is initialized successfully (can parse logs)
for( auto & dev : dev_copy )
{
try
if( auto logger = dev.as< rs2::firmware_logger >() )
{
if (auto fwlogger = dev.as<rs2::firmware_logger>())
bool can_parse = false;
std::string hwlogger_xml = config_file::instance().get( configurations::viewer::hwlogger_xml );
std::ifstream f( hwlogger_xml.c_str() );
if( f.good() )
{
bool has_parser = false;
std::string hwlogger_xml = config_file::instance().get(configurations::viewer::hwlogger_xml);
std::ifstream f(hwlogger_xml.c_str());
if (f.good())
try
{
try
{
std::string str((std::istreambuf_iterator<char>(f)),
std::istreambuf_iterator<char>());
fwlogger.init_parser(str);
has_parser = true;
}
catch (const std::exception& ex)
{
add_log( RS2_LOG_SEVERITY_WARN,
__FILE__,
__LINE__,
rsutils::string::from()
<< "Invalid Hardware Logger XML at '" << hwlogger_xml << "': " << ex.what()
<< "\nEither configure valid XML or remove it" );
continue; // Don't try to get log entries for this device
}
std::string str( ( std::istreambuf_iterator< char >( f ) ),
std::istreambuf_iterator< char >() );
can_parse = logger.init_parser( str );
}
catch( const std::exception & ex )
{
add_log( RS2_LOG_SEVERITY_WARN,
__FILE__,
__LINE__,
rsutils::string::from()
<< "Invalid Hardware Logger XML at '" << hwlogger_xml << "': " << ex.what()
<< "\nEither configure valid XML or remove it" );
continue; // Don't try to get log entries for this device
}
}

logger.start_collecting();
loggers.push_back( { logger, can_parse } );
}
}

fwlogger.start_collecting();
while( enable_firmware_logs )
{
for( auto & it : loggers )
{
auto & fwlogger = it.first;
bool can_parse = it.second;
try
{
auto message = fwlogger.create_message();
while (fwlogger.get_firmware_log(message))
while( fwlogger.get_firmware_log( message ) )
{
auto parsed = fwlogger.create_parsed_message();
auto parsed_ok = false;

if (has_parser)
if( can_parse )
{
if (fwlogger.parse_log(message, parsed))
if( fwlogger.parse_log( message, parsed ) )
{
parsed_ok = true;

std::string module_print = "[" + parsed.module_name() + "]";
if( module_print == "[Unknown]" )
module_print.clear(); // Some devices don't support FW log modules
module_print.clear(); // Some devices don't support FW log modules

add_log( message.get_severity(),
parsed.file_name(),
Expand All @@ -82,32 +94,39 @@ void output_model::thread_loop()
}
}

if (!parsed_ok)
if( ! parsed_ok )
{
std::stringstream ss;
for (auto& elem : message.data())
ss << std::setfill('0') << std::setw(2) << std::hex << static_cast<int>(elem) << " ";
add_log(message.get_severity(), __FILE__, 0, ss.str());
for( auto & elem : message.data() )
ss << std::setfill( '0' ) << std::setw( 2 ) << std::hex
<< static_cast< int >( elem ) << " ";
add_log( message.get_severity(), __FILE__, 0, ss.str() );
}
if( ! enable_firmware_logs && fwlogger.get_number_of_fw_logs() == 0 )
{
fwlogger.stop_collecting();

if( !enable_firmware_logs && fwlogger.get_number_of_fw_logs() == 0 )
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As I understand from the code, before if the user deactivate the log parsing, we continues dequeue until get_number_of_fw_logs() == 0
Now we will stop even we still have logs as our loop is while( enable_firmware_logs )
Is this change the required behavior?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

"Get logs" HWM can return multiple log entries at once. Those entries are put in a queue. Subsequent calls to get_firmware_log don't send HWM, only deque the messages.
get_number_of_fw_logs() == 0 when the queue is empty, then we break the loop and call stop_collecting

break;
}
}
}
catch( const std::exception & ex )
{
add_log( RS2_LOG_SEVERITY_WARN,
__FILE__,
__LINE__,
rsutils::string::from() << "Failed to fetch firmware logs: " << ex.what() );
}
}
catch(const std::exception& ex)
{
add_log( RS2_LOG_SEVERITY_WARN,
__FILE__,
__LINE__,
rsutils::string::from() << "Failed to fetch firmware logs: " << ex.what() );
}

// FW define the logs polling intervals to be no less than 100msec to cope with limited resources.
// At the same time 100 msec should guarantee no log drops
std::this_thread::sleep_for( std::chrono::milliseconds( 100 ) );
}
// FW define the logs polling intervals to be no less than 100msec to cope with limited resources.
// At the same time 100 msec should guarantee no log drops
std::this_thread::sleep_for(std::chrono::milliseconds(100));

// User dectivated FW logs. Stop collecting logs.
for( auto & fwlogger : loggers )
fwlogger.first.stop_collecting();
}

std::this_thread::sleep_for( std::chrono::milliseconds( 100 ) );
Nir-Az marked this conversation as resolved.
Show resolved Hide resolved
}
}

Expand Down
27 changes: 18 additions & 9 deletions src/firmware_logger_device.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -44,15 +44,16 @@ namespace librealsense
void firmware_logger_device::get_fw_logs_from_hw_monitor()
{
command update_command = get_update_command();
if( update_command.cmd == 0 )
return;

auto res = _hw_monitor->send( update_command );
if( res.empty() )
if( update_command.cmd != 0 )
{
return;
auto res = _hw_monitor->send( update_command );
if( ! res.empty() )
handle_received_data( res );
}
}

void firmware_logger_device::handle_received_data( const std::vector< uint8_t > & res )
{
// Convert bytes to fw_logs_binary_data
auto beginOfLogIterator = res.data();
size_t size_left = res.size();
Expand All @@ -61,7 +62,7 @@ namespace librealsense
size_t log_size = get_log_size( beginOfLogIterator );
if( log_size > size_left )
{
LOG_WARNING( "Received an incomplete FW log" ); // TODO - remove after debugging, or decrease to debug level.
LOG_WARNING( "Received an incomplete FW log" );
break;
}
auto endOfLogIterator = beginOfLogIterator + log_size;
Expand Down Expand Up @@ -176,7 +177,11 @@ namespace librealsense
command start_command = parser->get_start_command();
start_command.cmd = _fw_logs_command.cmd; // Opcode comes from the device, may be different between devices
if( start_command.cmd != 0 )
_hw_monitor->send( start_command );
{
auto res = _hw_monitor->send( start_command );
if( !res.empty() )
handle_received_data( res );
}
}

void extended_firmware_logger_device::stop()
Expand All @@ -188,7 +193,11 @@ namespace librealsense
command stop_command = parser->get_stop_command();
stop_command.cmd = _fw_logs_command.cmd; // Opcode comes from the device, may be different between devices
if( stop_command.cmd != 0 )
_hw_monitor->send( stop_command );
{
auto res = _hw_monitor->send( stop_command );
if( !res.empty() )
handle_received_data( res );
}
}

size_t extended_firmware_logger_device::get_log_size( const uint8_t * buff ) const
Expand Down
1 change: 1 addition & 0 deletions src/firmware_logger_device.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@ namespace librealsense

protected:
void get_fw_logs_from_hw_monitor();
void handle_received_data( const std::vector< uint8_t > & res );
void get_flash_logs_from_hw_monitor();
virtual command get_update_command();
virtual size_t get_log_size( const uint8_t * buff ) const;
Expand Down
Loading