From 0e1dcb8ff1abc269d4efce9bfeba12ac031db73f Mon Sep 17 00:00:00 2001 From: Eran Date: Thu, 5 Dec 2024 19:22:40 +0200 Subject: [PATCH 1/2] minor log error/info adjustments --- src/ds/d500/d500-device.cpp | 7 +++---- src/winusb/messenger-winusb.cpp | 2 +- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/src/ds/d500/d500-device.cpp b/src/ds/d500/d500-device.cpp index 6118e7e6ea..e33c9b144c 100644 --- a/src/ds/d500/d500-device.cpp +++ b/src/ds/d500/d500-device.cpp @@ -804,10 +804,9 @@ namespace librealsense constexpr size_t gvd_header_size = 8; auto gvd_payload_data = gvd_buff.data() + gvd_header_size; auto computed_crc = rsutils::number::calc_crc32( gvd_payload_data, parsed_fields->payload_size ); - LOG_INFO( "D500 GVD version is: " << static_cast< int >( parsed_fields->gvd_version[0] ) - << "." - << static_cast< int >( parsed_fields->gvd_version[1] ) ); - LOG_INFO( "D500 GVD payload_size is: " << parsed_fields->payload_size ); + LOG_DEBUG( "D500 GVD version is: " << static_cast< int >( parsed_fields->gvd_version[0] ) << "." + << static_cast< int >( parsed_fields->gvd_version[1] ) + << "\n\tD500 GVD payload_size is: " << parsed_fields->payload_size ); if( computed_crc != parsed_fields->crc32 ) { diff --git a/src/winusb/messenger-winusb.cpp b/src/winusb/messenger-winusb.cpp index 0dc61fadf0..4f1dbae40f 100644 --- a/src/winusb/messenger-winusb.cpp +++ b/src/winusb/messenger-winusb.cpp @@ -113,7 +113,7 @@ namespace librealsense if (!sts) { auto lastResult = GetLastError(); - LOG_ERROR("failed to set timeout policy, error: " << lastResult); + LOG_DEBUG( "failed to set timeout policy, error: " << lastResult ); return winusb_status_to_rs(lastResult); } return RS2_USB_STATUS_SUCCESS; From 26765f3bb87259f1b8cdffc7b6840f142b971baf Mon Sep 17 00:00:00 2001 From: Eran Date: Thu, 5 Dec 2024 19:24:44 +0200 Subject: [PATCH 2/2] fix compute_progress() bug; improve D500 FW update output --- src/ds/d500/d500-fw-update-device.cpp | 35 +++++++++++++-------------- src/fw-update/fw-update-device.cpp | 13 ++++++---- 2 files changed, 25 insertions(+), 23 deletions(-) diff --git a/src/ds/d500/d500-fw-update-device.cpp b/src/ds/d500/d500-fw-update-device.cpp index 30fabe2191..997773fdee 100644 --- a/src/ds/d500/d500-fw-update-device.cpp +++ b/src/ds/d500/d500-fw-update-device.cpp @@ -41,7 +41,7 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info if (!_is_dfu_monitoring_enabled) { - LOG_DEBUG("Waiting for the FW to be burnt"); + LOG_INFO( "Applying FW image ..." ); static constexpr int D500_FW_DFU_TIME = 120; // [sec] report_progress_and_wait_for_fw_burn(update_progress_callback, D500_FW_DFU_TIME); } @@ -50,7 +50,6 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info bool ds_d500_update_device::wait_for_manifest_completion(std::shared_ptr messenger, const rs2_dfu_state state, std::chrono::seconds timeout_seconds, rs2_update_progress_callback_sptr update_progress_callback) const { - std::chrono::seconds elapsed_seconds; auto start = std::chrono::system_clock::now(); rs2_dfu_state dfu_state = RS2_DFU_STATE_APP_IDLE; dfu_status_payload status; @@ -60,13 +59,18 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info // when this DFU progress is enabled by FW int max_iteration_number_for_progress_start = 10; - do { + do + { uint32_t transferred = 0; auto sts = messenger->control_transfer(0xa1 /*DFU_GETSTATUS_PACKET*/, RS2_DFU_GET_STATUS, 0, 0, (uint8_t*)&status, sizeof(status), transferred, 5000); dfu_state = status.get_state(); percentage_of_transfer = static_cast(status.iString); - // the below code avoids process stuck when using a d5XX device, + LOG_DEBUG( "DFU_GETSTATUS: " << platform::usb_status_to_string[sts] << "; state " << dfu_state + << "; iString " << percentage_of_transfer << "; bwPollTimeOut " + << status.bwPollTimeout ); + + // the below code avoids process stuck when using a d5XX device, // which has a fw version without the DFU progress feature if (percentage_of_transfer == 0 && ++iteration == max_iteration_number_for_progress_start) @@ -75,20 +79,15 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info return true; } - LOG_DEBUG( "DFU_GETSTATUS called, state is: " << dfu_state << ", iString equals: " << percentage_of_transfer - << ", and bwPollTimeOut equals: " << status.bwPollTimeout ); - if (update_progress_callback) { - auto progress_for_bar = compute_progress(static_cast(percentage_of_transfer), 20.f, 100.f, 5.f) / 100.f; + auto progress_for_bar = compute_progress(percentage_of_transfer / 100.f, 20.f, 100.f, 0.f) / 100.f; update_progress_callback->on_update_progress(progress_for_bar); } - if (sts != platform::RS2_USB_STATUS_SUCCESS) - LOG_ERROR("control xfer error: " << platform::usb_status_to_string[sts]); - - //test for dfu error state - if (status.is_error_state()) { + if( status.is_error_state() ) + { + LOG_WARNING( "Control transfer error" ); return false; } @@ -96,7 +95,7 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info std::this_thread::sleep_for(std::chrono::seconds(1)); auto curr = std::chrono::system_clock::now(); - elapsed_seconds = std::chrono::duration_cast(curr - start); + auto elapsed_seconds = std::chrono::duration_cast< std::chrono::seconds >( curr - start ); if (elapsed_seconds > timeout_seconds) { LOG_ERROR("DFU in MANIFEST STATUS Timeout"); @@ -143,7 +142,7 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info for (int i = 1; i <= 100; i++) { auto percentage_of_transfer = i; - auto progress_for_bar = compute_progress(static_cast(percentage_of_transfer), 20.f, 100.f, 5.f) / 100.f; + auto progress_for_bar = compute_progress(percentage_of_transfer / 100.f, 20.f, 100.f, 0.f) / 100.f; update_progress_callback->on_update_progress(progress_for_bar); std::this_thread::sleep_for(std::chrono::milliseconds(static_cast(iteration_sleep_time_ms))); } @@ -153,8 +152,8 @@ ds_d500_update_device::ds_d500_update_device( std::shared_ptr< const device_info } float ds_d500_update_device::compute_progress(float progress, float start, float end, float threshold) const { - if (threshold < 1.f) - throw std::invalid_argument("Avoid division by zero"); - return start + (ceil(progress * threshold) / threshold) * (end - start) / 100.f; + if( threshold > 1.f ) + progress = ceil( progress * threshold ) / threshold; + return start + progress * ( end - start ); } } diff --git a/src/fw-update/fw-update-device.cpp b/src/fw-update/fw-update-device.cpp index b04c23bacc..7d3e10e1ad 100644 --- a/src/fw-update/fw-update-device.cpp +++ b/src/fw-update/fw-update-device.cpp @@ -147,9 +147,10 @@ namespace librealsense float update_device::compute_progress(float progress, float start, float end, float threshold) const { - if (threshold < 1.f) - throw std::invalid_argument("Avoid division by zero"); - return start + (ceil(progress * threshold) / threshold) * (end - start) / 100.f; + // NOTE: this is usually overriden; see derived classes! + if( threshold > 1.f ) + progress = ceil( progress * threshold ) / threshold; + return start + progress * (end - start); } update_device::update_device( std::shared_ptr< const device_info > const & dev_info, @@ -252,10 +253,10 @@ namespace librealsense { // Only update every half-second to avoid spurious callbacks // (we can get here many many times in a split second) - LOG_DEBUG( "fw update progress: " << progress ); + LOG_DEBUG( "transfer progress: " << progress ); if( update_progress_callback ) { - auto progress_for_bar = compute_progress( progress, 0.f, 20.f, 5.f ) / 100.f; + auto progress_for_bar = compute_progress( progress, 0.f, 20.f, 0.f ) / 100.f; update_progress_callback->on_update_progress( progress_for_bar ); } sw.reset(); @@ -270,6 +271,7 @@ namespace librealsense if (sts != platform::RS2_USB_STATUS_SUCCESS) throw std::runtime_error("Failed to send final FW packet"); + LOG_INFO( "Resetting device ..." ); dfu_manifest_phase(messenger, update_progress_callback); } @@ -338,6 +340,7 @@ namespace librealsense void update_device::update(const void* fw_image, int fw_image_size, rs2_update_progress_callback_sptr update_progress_callback) const { + LOG_INFO( "Uploading FW image ..." ); if(_pid == "ABCD" || _pid == "BBCD") { update_mipi(fw_image, fw_image_size, update_progress_callback);