Add trace-level logging via the log facade
#51
Conversation
|
|
||
| bitcoin_hashes = "0.14.0" | ||
| chacha20-poly1305 = "0.1.2" | ||
| log = { version = "0.4.29", default-features = false, features = ["std"]} |
There was a problem hiding this comment.
Seems fine for now given its already in the transitive dep set, but post-#52 it presumably won't be and we'll have to revert this. What's the plan after that?
There was a problem hiding this comment.
Well, the log facade is the default for logging across most Rust crates. So we might actually want to consider adding (optional) log-based logging support to bitreq as otherwise we will lose a lot of insight when making the switch.
FWIW, before we integrated it in LDK Node, we had multiple users entirely confused why LDK Node logs were absent from their logs, until their realized we did something custom that didn't have the expected compatibility what ~every other project does. While I agree that we should be cautious with additional dependencies, sharing a usable and expected interface is important. So taking a dependency on log seems entirely worth for me, especially, if we, as we now did in lightningdevkit/ldk-server#76, don't take additional dependencies for the actual default consumer.
IMO, across projects we could also eventually consider taking a similar path w.r.t tracing: we could just take a dependency on tracing_core and (re-)implement the rest ourselves.
There was a problem hiding this comment.
IMO, across projects we could also eventually consider taking a similar path w.r.t tracing: we could just take a dependency on tracing_core and (re-)implement the rest ourselves.
I think you just undercut your argument around log being the way that we have to do logging here :). Many things use log, but not everything, with tokio pushing tracing instead its certainly not universal. Having optional dependencies on log/tracing, of course, is perfectly reasonable, but ultimately when we support both we'll need some kind of unified underlying logging interface again...
| ) -> Result<GetObjectResponse, VssError> { | ||
| retry( | ||
| let request_id: u64 = rand::random(); | ||
| trace!("Sending GetObjectRequest {} for key {}.", request_id, request.key); |
There was a problem hiding this comment.
In the happy case do we want a confirmation that the operation was successful ? I would expect to see one myself, but I may get used to "silence" == success.
There was a problem hiding this comment.
Hmm, yeah, it think it might be a bit spammy to also always log for the success case.
| error: &err, | ||
| }) { | ||
| trace!( | ||
| "Operation failed on attempt {}, retrying in {}ms: {}", |
There was a problem hiding this comment.
May not be necessary because once we've exhausted all attempts, we do log the request_id with the final failure message, but wondering if we want it here too.
There was a problem hiding this comment.
But we don't have access to the request_id here?
There was a problem hiding this comment.
Sure maybe we could have added a parameter to retry, but it's overkill for now
tankyleo
left a comment
tankyleo
left a comment
There was a problem hiding this comment.
Do we want to log the version too ? I know we don't use it now, but we are planning to use it by the next ldk-node release
Hmm, which ones though? The |
|
👋 Thanks for assigning @tankyleo as a reviewer! |
|
🔔 1st Reminder Hey @tankyleo! This PR has been waiting for your review. |
src/client.rs
Outdated
| trace!( | ||
| "Sending DeleteObjectRequest {} for key {:?}", | ||
| request_id, | ||
| request.key_value.iter().map(|t| &t.key) |
There was a problem hiding this comment.
let's replace this with request.key_value.as_ref().map(|t| &t.key) ?
At the moment this line looks like this:
Sending DeleteObjectRequest 14665000019760149953 for key Map { iter: Iter { inner: Item { opt: Some(KeyValue { key: "hello", version: -1, value: [] }) } } }
with the replacement we get:
Sending DeleteObjectRequest 11048689160446419397 for key Some("hello")
There was a problem hiding this comment.
Ah, good catch! Now force-pushed with the following changes:
> git diff-tree -U2 9c0ce05 bfa91e6
diff --git a/src/client.rs b/src/client.rs
index 3aed0eb..9f6b04a 100644
--- a/src/client.rs
+++ b/src/client.rs
@@ -143,5 +143,5 @@ impl<R: RetryPolicy<E = VssError>> VssClient<R> {
"Sending DeleteObjectRequest {} for key {:?}",
request_id,
- request.key_value.iter().map(|t| &t.key)
+ request.key_value.as_ref().map(|t| &t.key)
);
let res = retry(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.
tnull
force-pushed
the
2025-12-add-logging
branch
from
9c0ce05 to
bfa91e6
Compare
|
Thank you for the PR ! |
4 participants
We recently stumbled across some harder to debug issues that highlighted that the absence of logging in
vss-client-ngcan be a pain. Therefore, we here introduce logging for requests and the retry logic based on thelogfacade, 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.