Skip to content

Conversation

LagginTimes
Copy link
Contributor

@LagginTimes LagginTimes commented Jul 18, 2025

Resolves #1934.

Description

This PR refactors BDK’s tracing instrumentation by introducing a new internal crate, bdk_common, and replacing the old tracing-logs feature with a workspace-wide log feature:

  • New crate: bdk_common with macros log_trace!, log_debug!, log_info!, log_warn!, log_error!, and log_span!
  • Unified feature: log (disabled by default) pulls in tracing = "0.1" for all chain-sync crates
  • Macro-gated logging: swaps out #[cfg(feature = "tracing-logs")] use tracing… and trace!/debug! calls for log_trace!/log_span! invocations with structured fields
  • Zero overhead: with --no-default-features (i.e. no log), all logging macros become no-ops and tracing is not included

Coverage remains broad—entry points like full_scan, sync, mempool_at, next_block, etc., now use structured field records via the new macros.

Notes to the reviewers

Example code on the tracing_example branch:
https://github.com/LagginTimes/bdk/tree/tracing_example

Sample trace excerpt:

2025-08-06T09:23:18.244470Z TRACE bdk_electrum::full_scan{event="enter_full_scan" stop_gap=5 batch_size=25 fetch_prev=false}: …
2025-08-06T09:23:18.342270Z TRACE bdk_electrum::full_scan{…}: bdk_electrum::bdk_electrum_client: event="script_history_batch" batch_size=25
2025-08-06T09:23:18.505782Z TRACE bdk_electrum::full_scan{…}: bdk_electrum::bdk_electrum_client: event="tx_cache_hit" txid=5d1128104e7fd239b…
2025-08-06T09:23:18.758598Z TRACE bdk_electrum::full_scan{…}: bdk_electrum::bdk_electrum_client: event="anchor_cache_miss" txid=5d1128104e7fd239b… height=255638
2025-08-06T09:23:18.885780Z TRACE bdk_electrum::full_scan{…}: bdk_electrum::bdk_electrum_client: event="anchor_inserted" txid=5d1128104e7fd239b… height=255638 hash=00000006c93e9f…
2025-08-06T09:23:19.012345Z TRACE bdk_electrum::full_scan{…}: electrum_client::raw_client: ==> {"jsonrpc":"2.0","method":"blockchain.transaction.get_merkle",…}
2025-08-06T09:23:19.080123Z TRACE bdk_electrum::full_scan{…}: bdk_electrum::bdk_electrum_client: event="merkle_cache_hit" txid=5d1128104e7fd239b… height=255638

Changelog notice

  • Added bdk_common crate with feature-gated logging macros.
  • Introduced workspace-wide log feature in all chain crates to enable tracing‑based instrumentation.

Checklists

All Submissions:

New Features:

  • I've added tests for the new feature
  • I've added docs for the new feature

Bugfixes:

  • This pull request breaks the existing API
  • I've added tests to reproduce the issue which are now passing
  • I'm linking the issue being fixed by this PR

@LagginTimes LagginTimes self-assigned this Jul 18, 2025
@LagginTimes LagginTimes marked this pull request as draft July 18, 2025 18:41
Copy link
Member

@evanlinjin evanlinjin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for working on this.

It's quite inconvenient to repeat #[cfg(feature = "tracing-logs")] for every line logged.

How about we introduce some macros to solve this. These macros need to be shared across the whole workspace. I propose introducing an internal crate to the workspace (i.e. named common). Crates can be marked internal by setting the package.publish flag in Cargo.toml.

// crates/common/src/lib.rs

#[cfg(feature = "log")]
pub use tracing;

#[macro_use]
mod macros;
// crates/common/src/log.rs

#[cfg(feature = "log")]
#[macro_export]
macro_rules! log_trace {
    ($($tt:tt)*) => {
        tracing::trace!($($tt)*);
    };
}
#[cfg(not(feature = "log"))]
#[macro_export]
macro_rules! log_trace {
    ($($tt:tt)*) => {};
}

// Also have macros for debug, info, etc.
// crates/{downstream_crate}/Cargo.toml

[dependencies]
bdk_common = { path = "../common"}

[features]
// Forward log feature.
log = ["bdk_common/log"]
// crates/{downstream_crate}/src/lib.rs

#[macro_use]
extern crate bdk_common;

// Usage:
log_trace!("This will only log if `log` is enabled");

I would also rename the feature flag from tracing-logs to just log. There are only two widely used logging libraries in the rust ecosystem (tracing and log) and they are both interoperable so we wouldn't need multiple "logging backends".

Let me know what you think.

@LagginTimes LagginTimes force-pushed the tracing_feature branch 2 times, most recently from 85c6d2b to 65988f1 Compare August 5, 2025 10:26
Copy link
Contributor

@nymius nymius left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is looking good. Could you add some trace logs in the description during a usual execution flow?

@@ -104,6 +113,15 @@ impl<E: ElectrumApi> BdkElectrumClient<E> {
let mut request: FullScanRequest<K> = request.into();
let start_time = request.start_time();

let _span = log_span!(
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've just discovered the instrument tracing macro, maybe is helpful in these cases.

@notmandatory notmandatory added the new feature New feature or request label Aug 7, 2025
@notmandatory notmandatory moved this to In Progress in BDK Chain Aug 7, 2025
Copy link
Contributor

@oleonardolima oleonardolima left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

cACK 0f4a3b1

It's looking good, I think nymius's suggestion of instrumenting the functions is a good idea.

I also wonder if it's useful using some sort of correlation id (e.g uuid) so it's possible to correlate all logs related to each specific call/request, e.g full_scan/sync call or electrum/esplora requests.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
new feature New feature or request
Projects
Status: In Progress
Development

Successfully merging this pull request may close these issues.

Consider adding support for tracing
5 participants