Skip to content

feat: add opt-in structured logging #253

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

Open
EliteCoder18 wants to merge 2 commits into
base: master
Choose a base branch
from
Open

feat: add opt-in structured logging #253

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
348e29f
feat(log): add opt-in tracing events
EliteCoder18 Sep 5, 2026
97e5107
test(log): cover tracing events and log compatibility
EliteCoder18 Sep 5, 2026
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
2 changes: 2 additions & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@

### Added

* feat(log): add opt-in structured logging for client construction and HTTP requests [#253]

### Changed

* feat(client): enable request pipelining for `AsyncClient` [#245]
Expand Down
38 changes: 30 additions & 8 deletions Cargo-minimal.lock
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -264,9 +264,9 @@ dependencies = [

[[package]]
name = "cfg-if"
version = "0.1.2"
version = "0.1.6"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d4c819a1287eb618df47cc647173c5c4c66ba19d888a6e50d605672aed3140de"
checksum = "082bb9b28e00d3c9d39cc03e64ce4cea0f1bb9b3fde493f0cbc008472d22bdf4"

[[package]]
name = "cfg-if"
Expand Down Expand Up @@ -402,6 +402,7 @@ dependencies = [
"electrsd",
"flate2",
"hex-conservative 0.2.2",
"log",
"mio 0.8.11",
"openssl",
"openssl-sys",
Expand All @@ -411,6 +412,7 @@ dependencies = [
"tar",
"tempfile",
"tokio",
"tracing",
]

[[package]]
Expand All @@ -421,11 +423,11 @@ checksum = "6999dc1837253364c2ebb0704ba97994bd874e8f195d665c50b7548f6ea92764"

[[package]]
name = "filetime"
version = "0.2.13"
version = "0.2.8"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "0c122a393ea57648015bf06fbd3d372378992e86b9ff5a7a497b076a28c79efe"
checksum = "1ff6d4dab0aa0c8e6346d46052e93b13a16cf847b54ed357087c35011048cc7d"
dependencies = [
"cfg-if 1.0.0",
"cfg-if 0.1.6",
"libc",
"redox_syscall 0.1.0",
"winapi",
Expand Down Expand Up @@ -547,11 +549,11 @@ dependencies = [

[[package]]
name = "log"
version = "0.4.8"
version = "0.4.17"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "14b6052be84e6b71ab17edffc2eeabf5c2c3ae1fdb464aae35ac50c67a44e1f7"
checksum = "abb12e687cfb44aa40f41fc3978ef76448f9b6038cad6aef4259d3c095a2382e"
dependencies = [
"cfg-if 0.1.2",
"cfg-if 1.0.0",
]

[[package]]
Expand Down Expand Up @@ -1100,6 +1102,26 @@ dependencies = [
"tokio",
]

[[package]]
name = "tracing"
version = "0.1.44"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100"
dependencies = [
"log",
"pin-project-lite",
"tracing-core",
]

[[package]]
name = "tracing-core"
version = "0.1.36"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a"
dependencies = [
"once_cell",
]

[[package]]
name = "unicode-ident"
version = "1.0.0"
Expand Down
22 changes: 22 additions & 0 deletions Cargo-recent.lock
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -339,6 +339,7 @@ dependencies = [
"electrsd",
"flate2",
"hex-conservative",
"log",
"mio 0.8.11",
"openssl",
"openssl-sys",
Expand All @@ -348,6 +349,7 @@ dependencies = [
"tar",
"tempfile",
"tokio",
"tracing",
]

[[package]]
Expand Down Expand Up @@ -1035,6 +1037,26 @@ dependencies = [
"tokio",
]

[[package]]
name = "tracing"
version = "0.1.44"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100"
dependencies = [
"log",
"pin-project-lite",
"tracing-core",
]

[[package]]
name = "tracing-core"
version = "0.1.36"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a"
dependencies = [
"once_cell",
]

[[package]]
name = "unicode-ident"
version = "1.0.24"
Expand Down
6 changes: 6 additions & 0 deletions Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,8 +26,10 @@ hex = { version = "0.2.2", package = "hex-conservative" }
serde = { version = "1.0.194", features = ["derive"] }
serde_json = { version = "1.0.117", features = ["std"], default-features = false }
tokio = { version = "1.44.2", features = ["time"], optional = true } # Async Client Transport
tracing = { version = "0.1.44", default-features = false, features = ["std", "log"], optional = true }

[dev-dependencies]
log = "0.4.17"
electrsd = { version = "0.41.0", default-features = false, features = ["legacy", "esplora_a33e97e1", "bitcoind_download", "bitcoind_29_0"] }
tokio = { version = "1.44.2", features = ["full"] }
# Transitive dependency pins:
Expand All @@ -45,6 +47,7 @@ tempfile = { version = ">=3.4.0, <=3.15.0" } # blame: remove_dir_all@0.5.0 -> te

[features]
default = ["blocking", "blocking-https", "async", "async-https", "tokio"]
log = ["dep:tracing"]

tokio = ["dep:tokio"]
async = ["bitreq/async", "bitreq/proxy", "bitreq/json-using-serde", "tokio?/time"]
Expand Down Expand Up @@ -95,6 +98,9 @@ exclude_features = [
# Run tests using these exact feature sets
exact_features = [
["async", "blocking"],
["async", "log"],
["blocking", "log"],
["async", "blocking", "log"],
["async-https", "blocking-https", "tokio"],
["async-https-native", "blocking-https-native", "tokio"],
["async-https-rustls", "blocking-https-rustls", "tokio"],
Expand Down
59 changes: 57 additions & 2 deletions src/async.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -100,6 +100,16 @@ impl<S: Sleeper> AsyncClient<S> {
/// Returns an [`Error`] if the HTTP client fails to build,
/// or if any of the provided header names or values are invalid.
pub fn from_builder(builder: Builder) -> Result<Self, Error> {
log_debug!(
event = "client_build",
client = "async",
timeout = ?builder.timeout,
max_retries = builder.max_retries,
max_connections = builder.max_connections,
proxy_configured = builder.proxy.is_some(),
header_count = builder.headers.len(),
"building Esplora client"
);
Ok(AsyncClient {
url: builder.base_url,
proxy: builder.proxy,
Expand Down Expand Up @@ -150,7 +160,7 @@ impl<S: Sleeper> AsyncClient<S> {
Ok(request)
}

/// Sends a GET request to `url`, retrying on retryable status codes
/// Sends a GET request to `path`, retrying on retryable status codes
/// with exponential backoff until [`AsyncClient::max_retries`] is reached.
async fn get_with_retry(&self, path: &str) -> Result<Response, Error> {
let mut delay = BASE_BACKOFF_MILLIS;
Expand All @@ -159,8 +169,36 @@ impl<S: Sleeper> AsyncClient<S> {
let request = self.build_request(Method::Get, path)?.with_pipelining();

loop {
match request.clone().send_async_with_client(&self.client).await? {
log_trace!(
event = "request",
client = "async",
method = "GET",
path,
attempt = attempts + 1,
"sending Esplora request"
);
let response = request.clone().send_async_with_client(&self.client).await?;
log_trace!(
event = "response",
client = "async",
method = "GET",
path,
attempt = attempts + 1,
status = response.status_code,
"received Esplora response"
);
match response {
response if attempts < self.max_retries && is_retryable(&response) => {
log_debug!(
event = "retry",
client = "async",
method = "GET",
path,
attempt = attempts + 1,
status = response.status_code,
delay_ms = delay.as_millis(),
"retrying Esplora request"
);
S::sleep(delay).await;
attempts += 1;
delay *= 2;
Expand Down Expand Up @@ -324,7 +362,24 @@ impl<S: Sleeper> AsyncClient<S> {
request = request.with_param(key, value);
}

log_trace!(
event = "request",
client = "async",
method = "POST",
path,
attempt = 1,
"sending Esplora request"
);
let response = request.send_async_with_client(&self.client).await?;
log_trace!(
event = "response",
client = "async",
method = "POST",
path,
attempt = 1,
status = response.status_code,
"received Esplora response"
);

if !is_success(&response) {
let status = u16::try_from(response.status_code).map_err(Error::StatusCode)?;
Expand Down
61 changes: 58 additions & 3 deletions src/blocking.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -86,6 +86,15 @@ impl BlockingClient {
/// This consumes the builder configuration and stores it on the client.
/// No network request is made until a client method is called.
pub fn from_builder(builder: Builder) -> Self {
log_debug!(
event = "client_build",
client = "blocking",
timeout = ?builder.timeout,
max_retries = builder.max_retries,
proxy_configured = builder.proxy.is_some(),
header_count = builder.headers.len(),
"building Esplora client"
);
Self {
url: builder.base_url,
proxy: builder.proxy,
Expand Down Expand Up @@ -145,7 +154,24 @@ impl BlockingClient {
request = request.with_param(key, value);
}

log_trace!(
event = "request",
client = "blocking",
method = "POST",
path,
attempt = 1,
"sending Esplora request"
);
let response = request.send()?;
log_trace!(
event = "response",
client = "blocking",
method = "POST",
path,
attempt = 1,
status = response.status_code,
"received Esplora response"
);

if !is_success(&response) {
let status = u16::try_from(response.status_code).map_err(Error::StatusCode)?;
Expand All @@ -156,15 +182,44 @@ impl BlockingClient {
Ok(response)
}

/// Sends a GET request to `url`, retrying on retryable status codes
/// Sends a GET request to `path`, retrying on retryable status codes
/// with exponential backoff until [`BlockingClient::max_retries`] is reached.
fn get_with_retry(&self, url: &str) -> Result<Response, Error> {
fn get_with_retry(&self, path: &str) -> Result<Response, Error> {
let mut delay = BASE_BACKOFF_MILLIS;
let mut attempts = 0;

loop {
match self.build_request(Method::Get, url)?.send()? {
let request = self.build_request(Method::Get, path)?;
log_trace!(
event = "request",
client = "blocking",
method = "GET",
path,
attempt = attempts + 1,
"sending Esplora request"
);
let response = request.send()?;
log_trace!(
event = "response",
client = "blocking",
method = "GET",
path,
attempt = attempts + 1,
status = response.status_code,
"received Esplora response"
);
match response {
resp if attempts < self.max_retries && is_retryable(&resp) => {
log_debug!(
event = "retry",
client = "blocking",
method = "GET",
path,
attempt = attempts + 1,
status = resp.status_code,
delay_ms = delay.as_millis(),
"retrying Esplora request"
);
thread::sleep(delay);
attempts += 1;
delay *= 2;
Expand Down
30 changes: 29 additions & 1 deletion src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,8 @@
//!
//! # Features
//!
//! By default the crate enables all features. To select only the pieces you
//! By default the crate enables both clients, their default TLS backends, and Tokio.
//! Logging is opt-in. To select only the pieces you
//! need, set `default-features = false` in `Cargo.toml` and list the desired
//! features explicitly:
//!
Expand All @@ -83,8 +84,19 @@
//! * `async-https-rustls-probe` enables [`bitreq`], the async client with support for proxying and
//! TLS (SSL) using `rustls` and probed system roots.
//! * `tokio` enables the default async sleeper used by [`Builder::build_async`].
//! * `log` enables structured [`tracing`] events. Disabled by default.
//!
//! # Logging
//!
//! The `log` feature emits `DEBUG` events for client construction and retries,
//! and `TRACE` events for HTTP requests and responses.
//!
//! The application must configure either a tracing subscriber or a `log` logger.
//! Headers, bodies, base URLs, and proxy values are omitted. Request paths are
//! included and may contain addresses or transaction IDs.
//!
//! [Esplora]: https://github.com/Blockstream/esplora/blob/master/API.md
//! [tracing]: https://docs.rs/tracing
//! [`bitreq`]: https://docs.rs/bitreq
#![allow(clippy::result_large_err)]
#![warn(missing_docs)]
Expand All @@ -98,6 +110,22 @@ use std::time::Duration;
#[cfg(feature = "async")]
pub use r#async::Sleeper;

#[cfg(any(feature = "blocking", feature = "async"))]
macro_rules! log_debug {
($($arg:tt)*) => {{
#[cfg(feature = "log")]
tracing::debug!($($arg)*);
}};
}

#[cfg(any(feature = "blocking", feature = "async"))]
macro_rules! log_trace {
($($arg:tt)*) => {{
#[cfg(feature = "log")]
tracing::trace!($($arg)*);
}};
}

pub mod api;
#[cfg(feature = "async")]
pub mod r#async;
Expand Down
Loading
Loading