Skip to content
Merged
24 changes: 12 additions & 12 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

17 changes: 9 additions & 8 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -52,14 +52,14 @@ members = [
]

[workspace.dependencies]
dashcore = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
dash-network-seeds = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
dash-spv = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
key-wallet = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
key-wallet-ffi = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
key-wallet-manager = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
dash-network = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
dashcore-rpc = { git = "https://github.com/dashpay/rust-dashcore", rev = "173ffac0fdc0c73dda0626cf385bbcfcf2437aeb" }
dashcore = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
dash-network-seeds = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
dash-spv = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
key-wallet = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
key-wallet-ffi = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
key-wallet-manager = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
dash-network = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }
dashcore-rpc = { git = "https://github.com/dashpay/rust-dashcore", rev = "bec50270cadb171f41bc61f63b6589eedc2edf0e" }

tokio-metrics = "0.5"

Expand Down Expand Up @@ -130,3 +130,4 @@ opt-level = 3

version = "4.2.0-dev.1"
rust-version = "1.92"

21 changes: 19 additions & 2 deletions packages/rs-platform-wallet-ffi/src/logging.rs
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,19 @@ pub unsafe extern "C" fn platform_wallet_enable_file_logging(
enable_file_logging(level_to_directive(level), &path)
}

/// Level for the network-diagnostics targets (`rs_dapi_client`,
/// `rs_sdk_trusted_context_provider`): their useful events (per-request
/// execution, address ban/unban, quorum cache misses) sit at `debug`, so
/// they get at least that regardless of the caller's global level — but a
/// caller asking for `trace` still gets `trace`.
fn diag_level(log_level: &str) -> &str {
if log_level == "trace" {
"trace"
} else {
"debug"
}
}

fn enable_file_logging(log_level: &str, path: &Path) -> bool {
let Some(f_sdk) = open_file(path.join("dash_sdk").join("run.log")) else {
return false;
Expand Down Expand Up @@ -107,7 +120,9 @@ fn enable_file_logging(log_level: &str, path: &Path) -> bool {
.with_ansi(false)
.with_filter(tracing_subscriber::EnvFilter::new(format!(
"dapi_grpc={log_level},tonic={log_level},h2={log_level},\
hyper={log_level},tower={log_level}"
hyper={log_level},tower={log_level},\
rs_dapi_client={diag},rs_sdk_trusted_context_provider={diag}",
diag = diag_level(log_level)
)));

if fs::write(path.join("build_info.txt"), build_info_string()).is_err() {
Expand Down Expand Up @@ -157,7 +172,9 @@ fn broad_env_filter(log_level: &str) -> tracing_subscriber::EnvFilter {
platform_wallet={log_level},platform_wallet_ffi={log_level},\
dash_spv={log_level},key_wallet={log_level},\
dapi_grpc={log_level},h2={log_level},tower={log_level},\
hyper={log_level},tonic={log_level}"
hyper={log_level},tonic={log_level},\
rs_dapi_client={diag},rs_sdk_trusted_context_provider={diag}",
diag = diag_level(log_level)
);

tracing_subscriber::EnvFilter::try_from_default_env()
Expand Down
42 changes: 40 additions & 2 deletions packages/rs-sdk-trusted-context-provider/src/provider.rs
Original file line number Diff line number Diff line change
Expand Up @@ -706,14 +706,52 @@ impl ContextProvider for TrustedHttpContextProvider {
)));
}

// This network refetch blocks the caller (proof verification) and
// re-runs on every retry of the outer request, so record how long
// it takes. `Instant` is unavailable on wasm32; those builds log
// `elapsed_ms=None` rather than a fabricated duration.
#[cfg(not(target_arch = "wasm32"))]
let started = std::time::Instant::now();
#[cfg(not(target_arch = "wasm32"))]
let elapsed_ms = move || Some(started.elapsed().as_millis() as u64);
#[cfg(target_arch = "wasm32")]
let elapsed_ms = || None::<u64>;

tracing::info!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
"quorum cache miss; blocking refetch of quorum lists"
);

let this = self.clone();
let quorum =
dash_async::block_on(async move { this.find_quorum(quorum_type, quorum_hash).await })?
dash_async::block_on(async move { this.find_quorum(quorum_type, quorum_hash).await })
.map_err(|e| {
debug!("Error finding quorum: {}", e);
tracing::warn!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch failed to execute: {}", e
);
e
})?
.map_err(|e| {
tracing::warn!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch failed: {}", e
);
ContextProviderError::Generic(format!("Failed to find quorum: {}", e))
})?;
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Comment on lines 726 to 746

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

🟡 Suggestion: Log failures from the outer block_on result

The warning and elapsed time are attached only to the inner find_quorum result. When dash_async::block_on itself returns an AsyncError, the first ? exits after the start message without emitting a terminal failure diagnostic. This can happen during native runtime/thread bridging and is guaranteed on wasm32, where block_on is an unsupported-operation stub despite this path explicitly defining elapsed_ms=None for wasm. Log the outer error before propagating it so every started refetch records either success or failure.

Suggested change
let this = self.clone();
let quorum =
dash_async::block_on(async move { this.find_quorum(quorum_type, quorum_hash).await })?
.map_err(|e| {
debug!("Error finding quorum: {}", e);
tracing::warn!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch failed: {}", e
);
ContextProviderError::Generic(format!("Failed to find quorum: {}", e))
})?;
let this = self.clone();
let quorum =
dash_async::block_on(async move { this.find_quorum(quorum_type, quorum_hash).await })
.map_err(|e| {
tracing::warn!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch could not run: {}", e
);
e
})?
.map_err(|e| {
tracing::warn!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch failed: {}", e
);
ContextProviderError::Generic(format!("Failed to find quorum: {}", e))
})?;

source: ['codex']

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Right — the outer block_on error path exited after the "cache miss" info with no terminal diagnostic. Fixed in 4619b56: both the outer execution error and the inner find_quorum error now log a warn with elapsed_ms.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Resolved in 4619b56Log failures from the outer block_on result no longer present.

Auto-resolved by the review system based on the latest commit diff. If you believe this was closed in error, reopen the thread.


tracing::info!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch succeeded"
);

Self::parse_quorum_public_key(&quorum.key)
}

Expand Down
32 changes: 27 additions & 5 deletions packages/rs-sdk/src/platform/shielded/notes_sync/fetch_chunk.rs
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ use drive_proof_verifier::types::{
ShieldedEncryptedNote, ShieldedEncryptedNotes, ShieldedEncryptedNotesQuery,
};
use rs_dapi_client::RequestSettings;
use tracing::debug;
use tracing::{info, warn};

/// Fetch a single chunk of encrypted notes from the network.
///
Expand All @@ -28,21 +28,43 @@ pub async fn fetch_chunk(
count: chunk_size as u32,
};

debug!(chunk_start, chunk_size, "fetching shielded notes chunk");
info!(chunk_start, chunk_size, "fetching shielded notes chunk");

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

not sure why this should be info.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Fair — downgraded both to debug in f0a0df0. The wallet's file-logging harness opts back in with a targeted dash_sdk::platform::shielded=debug directive (same mechanism as rs_dapi_client), so the diagnostic export keeps per-chunk timings while the crate stays quiet at default levels.


let (result, metadata) =
ShieldedEncryptedNotes::fetch_with_metadata(sdk, query, Some(settings)).await?;
// `Instant` is unavailable on wasm32; a chunk fetched there logs
// `elapsed_ms=None` rather than a fabricated duration.
#[cfg(not(target_arch = "wasm32"))]
let started = std::time::Instant::now();
#[cfg(not(target_arch = "wasm32"))]
let elapsed_ms = move || Some(started.elapsed().as_millis() as u64);
#[cfg(target_arch = "wasm32")]
let elapsed_ms = || None::<u64>;

let fetched = ShieldedEncryptedNotes::fetch_with_metadata(sdk, query, Some(settings)).await;

let (result, metadata) = match fetched {
Ok(v) => v,
Err(e) => {
warn!(
chunk_start,
elapsed_ms = ?elapsed_ms(),
error = %e,
"shielded notes chunk fetch failed"
);
return Err(e);
}
};

let (notes, total_count) = match result {
Some(ShieldedEncryptedNotes { notes, total_count }) => (notes, total_count),
None => (Vec::new(), 0),
};

debug!(
info!(

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

I don't think this should be info.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Same fix — debug as of f0a0df0.

chunk_start,
notes_returned = notes.len(),
block_height = metadata.height,
total_count,
elapsed_ms = ?elapsed_ms(),
"shielded notes chunk fetched"
);

Expand Down
Loading
Loading