From 399c18acca48681e95b47dc1d643e34bbd952eb7 Mon Sep 17 00:00:00 2001 From: ohadmeir Date: Mon, 15 Apr 2024 12:54:44 +0300 Subject: [PATCH 1/3] Fix FW logs bug, did not parse logs returned for start command --- src/firmware_logger_device.cpp | 27 ++++++++++++++++++--------- src/firmware_logger_device.h | 1 + 2 files changed, 19 insertions(+), 9 deletions(-) diff --git a/src/firmware_logger_device.cpp b/src/firmware_logger_device.cpp index 71da2916f7..ce029b96de 100644 --- a/src/firmware_logger_device.cpp +++ b/src/firmware_logger_device.cpp @@ -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() ) + HandleReceivedData( res ); } + } + void firmware_logger_device::HandleReceivedData( std::vector< uint8_t > & res ) + { // Convert bytes to fw_logs_binary_data auto beginOfLogIterator = res.data(); size_t size_left = res.size(); @@ -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; @@ -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() ) + HandleReceivedData( res ); + } } void extended_firmware_logger_device::stop() @@ -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() ) + HandleReceivedData( res ); + } } size_t extended_firmware_logger_device::get_log_size( const uint8_t * buff ) const diff --git a/src/firmware_logger_device.h b/src/firmware_logger_device.h index 547eb9c48a..6cdcc8da60 100644 --- a/src/firmware_logger_device.h +++ b/src/firmware_logger_device.h @@ -49,6 +49,7 @@ namespace librealsense protected: void get_fw_logs_from_hw_monitor(); + void HandleReceivedData( 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; From 8cd2376f772b9dba46ab87fe0b1defda12f7a912 Mon Sep 17 00:00:00 2001 From: ohadmeir Date: Mon, 15 Apr 2024 12:55:51 +0300 Subject: [PATCH 2/3] Parse FW logs XML only once when starting to collect logs --- common/output-model.cpp | 123 +++++++++++++++++++++++----------------- 1 file changed, 71 insertions(+), 52 deletions(-) diff --git a/common/output-model.cpp b/common/output-model.cpp index fe335e9e75..937478a8b3 100644 --- a/common/output-model.cpp +++ b/common/output-model.cpp @@ -21,58 +21,70 @@ void output_model::thread_loop() { while (!to_stop) { - std::vector dev_copy; + if( enable_firmware_logs ) { - std::lock_guard 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 dev_copy; + { + std::lock_guard 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()) + 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(f)), - std::istreambuf_iterator()); - 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(), @@ -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(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 ) 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 ) ); } } From e4f0782ec8004cb011b055549dc50d09b3a1ae53 Mon Sep 17 00:00:00 2001 From: ohadmeir Date: Mon, 15 Apr 2024 14:18:55 +0300 Subject: [PATCH 3/3] fixup! Fix FW logs bug, did not parse logs returned for start command --- src/firmware_logger_device.cpp | 8 ++++---- src/firmware_logger_device.h | 2 +- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/src/firmware_logger_device.cpp b/src/firmware_logger_device.cpp index ce029b96de..bd07c08f39 100644 --- a/src/firmware_logger_device.cpp +++ b/src/firmware_logger_device.cpp @@ -48,11 +48,11 @@ namespace librealsense { auto res = _hw_monitor->send( update_command ); if( ! res.empty() ) - HandleReceivedData( res ); + handle_received_data( res ); } } - void firmware_logger_device::HandleReceivedData( std::vector< uint8_t > & 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(); @@ -180,7 +180,7 @@ namespace librealsense { auto res = _hw_monitor->send( start_command ); if( !res.empty() ) - HandleReceivedData( res ); + handle_received_data( res ); } } @@ -196,7 +196,7 @@ namespace librealsense { auto res = _hw_monitor->send( stop_command ); if( !res.empty() ) - HandleReceivedData( res ); + handle_received_data( res ); } } diff --git a/src/firmware_logger_device.h b/src/firmware_logger_device.h index 6cdcc8da60..3a5cd61473 100644 --- a/src/firmware_logger_device.h +++ b/src/firmware_logger_device.h @@ -49,7 +49,7 @@ namespace librealsense protected: void get_fw_logs_from_hw_monitor(); - void HandleReceivedData( std::vector< uint8_t > & res ); + 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;