From 9c0ce050b06263db6bc2edbfba985c4a4c3be73a Mon Sep 17 00:00:00 2001 From: Elias Rohrer Date: Wed, 17 Dec 2025 11:11:11 +0100 Subject: [PATCH] Add `trace`-level logging via the `log` facade We recently stumbled across some harder to debug issues that highlighted that the absence of logging in `vss-client-ng` can be a pain. Therefore, we here introduce logging for requests and the retry logic based on the `log` facade, which not only allows the logging to easily integrate with the Rust ecosystem, but is also a non-API breaking change allowing us to ship this in a patch release. --- Cargo.toml | 1 + src/client.rs | 58 ++++++++++++++++++++++++++++++++++++++++------- src/util/mod.rs | 20 ++++++++++++++++ src/util/retry.rs | 8 +++++++ 4 files changed, 79 insertions(+), 8 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 50527ac..a93eab9 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -31,6 +31,7 @@ serde_json = { version = "1.0.113", default-features = false, optional = true } bitcoin_hashes = "0.14.0" chacha20-poly1305 = "0.1.2" +log = { version = "0.4.29", default-features = false, features = ["std"]} [target.'cfg(genproto)'.build-dependencies] prost-build = { version = "0.11.3" } diff --git a/src/client.rs b/src/client.rs index cf80972..3aed0eb 100644 --- a/src/client.rs +++ b/src/client.rs @@ -5,6 +5,8 @@ use std::collections::HashMap; use std::default::Default; use std::sync::Arc; +use log::trace; + use crate::error::VssError; use crate::headers::{get_headermap, FixedHeaders, VssHeaderProvider}; use crate::types::{ @@ -12,6 +14,7 @@ use crate::types::{ ListKeyVersionsRequest, ListKeyVersionsResponse, PutObjectRequest, PutObjectResponse, }; use crate::util::retry::{retry, RetryPolicy}; +use crate::util::KeyValueVecKeyPrinter; const APPLICATION_OCTET_STREAM: &str = "application/octet-stream"; const DEFAULT_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(10); @@ -77,7 +80,9 @@ impl> VssClient { pub async fn get_object( &self, request: &GetObjectRequest, ) -> Result { - retry( + let request_id: u64 = rand::random(); + trace!("Sending GetObjectRequest {} for key {}.", request_id, request.key); + let res = retry( || async { let url = format!("{}/getObject", self.base_url); self.post_request(request, &url).await.and_then(|response: GetObjectResponse| { @@ -92,7 +97,11 @@ impl> VssClient { }, &self.retry_policy, ) - .await + .await; + if let Err(ref e) = res { + trace!("GetObjectRequest {} failed: {}", request_id, e); + } + res } /// Writes multiple [`PutObjectRequest::transaction_items`] as part of a single transaction. @@ -102,14 +111,25 @@ impl> VssClient { pub async fn put_object( &self, request: &PutObjectRequest, ) -> Result { - retry( + let request_id: u64 = rand::random(); + trace!( + "Sending PutObjectRequest {} for transaction_items {} and delete_items {}.", + request_id, + KeyValueVecKeyPrinter(&request.transaction_items), + KeyValueVecKeyPrinter(&request.delete_items), + ); + let res = retry( || async { let url = format!("{}/putObjects", self.base_url); self.post_request(request, &url).await }, &self.retry_policy, ) - .await + .await; + if let Err(ref e) = res { + trace!("PutObjectRequest {} failed: {}", request_id, e); + } + res } /// Deletes the given `key` and `value` in `request`. @@ -118,14 +138,24 @@ impl> VssClient { pub async fn delete_object( &self, request: &DeleteObjectRequest, ) -> Result { - retry( + let request_id: u64 = rand::random(); + trace!( + "Sending DeleteObjectRequest {} for key {:?}", + request_id, + request.key_value.iter().map(|t| &t.key) + ); + let res = retry( || async { let url = format!("{}/deleteObject", self.base_url); self.post_request(request, &url).await }, &self.retry_policy, ) - .await + .await; + if let Err(ref e) = res { + trace!("DeleteObjectRequest {} failed: {}", request_id, e); + } + res } /// Lists keys and their corresponding version for a given [`ListKeyVersionsRequest::store_id`]. @@ -134,14 +164,26 @@ impl> VssClient { pub async fn list_key_versions( &self, request: &ListKeyVersionsRequest, ) -> Result { - retry( + let request_id: u64 = rand::random(); + trace!( + "Sending ListKeyVersionsRequest {} for key_prefix {:?}, page_size {:?}, page_token {:?}", + request_id, + request.key_prefix, + request.page_size, + request.page_token + ); + let res = retry( || async { let url = format!("{}/listKeyVersions", self.base_url); self.post_request(request, &url).await }, &self.retry_policy, ) - .await + .await; + if let Err(ref e) = res { + trace!("ListKeyVersionsRequest {} failed: {}", request_id, e); + } + res } async fn post_request( diff --git a/src/util/mod.rs b/src/util/mod.rs index 7f40f97..c9362f4 100644 --- a/src/util/mod.rs +++ b/src/util/mod.rs @@ -1,3 +1,6 @@ +use crate::types::KeyValue; +use core::fmt; + /// Contains [`StorableBuilder`] utility. /// /// [`StorableBuilder`]: storable_builder::StorableBuilder @@ -10,3 +13,20 @@ pub mod retry; /// /// [`KeyObfuscator`]: key_obfuscator::KeyObfuscator pub mod key_obfuscator; + +pub(crate) struct KeyValueVecKeyPrinter<'a>(pub(crate) &'a Vec); + +impl fmt::Display for KeyValueVecKeyPrinter<'_> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + write!(f, "[")?; + for (i, k) in self.0.iter().enumerate() { + if i == self.0.len() - 1 { + write!(f, "{}", &k.key)?; + } else { + write!(f, "{}, ", &k.key)?; + } + } + write!(f, "]")?; + Ok(()) + } +} diff --git a/src/util/retry.rs b/src/util/retry.rs index 9155c8a..b7983ef 100644 --- a/src/util/retry.rs +++ b/src/util/retry.rs @@ -4,6 +4,8 @@ use std::future::Future; use std::marker::PhantomData; use std::time::Duration; +use log::trace; + /// A function that performs and retries the given operation according to a retry policy. /// /// **Caution**: A retry policy without the number of attempts capped by [`MaxAttemptsRetryPolicy`] @@ -69,6 +71,12 @@ where accumulated_delay, error: &err, }) { + trace!( + "Operation failed on attempt {}, retrying in {}ms: {}", + attempts_made, + delay.as_millis(), + err + ); tokio::time::sleep(delay).await; accumulated_delay += delay; } else {