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.

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

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

tokio-metrics = "0.5"

Expand Down
26 changes: 23 additions & 3 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 @@ -63,7 +76,9 @@ fn enable_file_logging(log_level: &str, path: &Path) -> bool {
.with_writer(Mutex::new(f_sdk))
.with_ansi(false)
.with_filter(tracing_subscriber::EnvFilter::new(format!(
"dash_sdk={log_level},rs_sdk_ffi={log_level},rs_sdk_ffi::metrics=off"
"dash_sdk={log_level},rs_sdk_ffi={log_level},rs_sdk_ffi::metrics=off,\
dash_sdk::platform::shielded={diag}",
diag = diag_level(log_level)
)));

let l_sdk_metrics = tracing_subscriber::fmt::layer()
Expand Down Expand Up @@ -107,7 +122,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 +174,10 @@ 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},\
dash_sdk::platform::shielded={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::debug!(
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::debug!(
quorum_type,
quorum_hash = %hex::encode(quorum_hash),
elapsed_ms = ?elapsed_ms(),
"quorum refetch succeeded"
);

Self::parse_quorum_public_key(&quorum.key)
}

Expand Down
28 changes: 25 additions & 3 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::{debug, warn};

/// Fetch a single chunk of encrypted notes from the network.
///
Expand All @@ -30,8 +30,29 @@ pub async fn fetch_chunk(

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

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),
Expand All @@ -43,6 +64,7 @@ pub async fn fetch_chunk(
notes_returned = notes.len(),
block_height = metadata.height,
total_count,
elapsed_ms = ?elapsed_ms(),
"shielded notes chunk fetched"
);

Expand Down
Loading
Loading