Skip to content

Add canonical tracing event macros #2511

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

Merged
Mirko-von-Leipzig merged 1 commit into from
Aug 27, 2026
Merged

Add canonical tracing event macros #2511

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
4 changes: 4 additions & 0 deletions bin/network-monitor/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,10 @@ version.workspace = true
[lints]
workspace = true

[package.metadata.cargo-shear]
# Required by expansions of the Miden tracing macros.
ignored = ["tracing"]

[dependencies]
anyhow = { workspace = true }
axum = { workspace = true }
Expand Down
5 changes: 2 additions & 3 deletions bin/network-monitor/src/commands/start.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,7 @@

use anyhow::Result;
use miden_node_utils::logging::OpenTelemetry;
use miden_node_utils::tracing::miden_instrument;
use tracing::info;
use miden_node_utils::tracing::{info, miden_instrument};

use crate::config::MonitorConfig;
use crate::frontend::ServerState;
Expand All @@ -28,7 +27,7 @@ use crate::{COMPONENT, LOG_TARGET};
err,
)]
pub async fn start_monitor(config: MonitorConfig) -> Result<()> {
info!(target: LOG_TARGET, config = ?config, "Loaded configuration");
info!(target: LOG_TARGET, "Loaded configuration", port = config.port);

let _otel_guard =
miden_node_utils::logging::setup_tracing(OpenTelemetry::from_env().with_name("monitor"))?;
Expand Down
89 changes: 44 additions & 45 deletions bin/network-monitor/src/counter.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ use std::time::{Duration, Instant};
use anyhow::{Context, Result};
use miden_node_proto::clients::RpcClient;
use miden_node_utils::spawn::spawn_blocking_in_current_span;
use miden_node_utils::tracing::miden_instrument;
use miden_node_utils::tracing::{debug, error, info, miden_instrument, warn};
use miden_protocol::account::auth::AuthSecretKey;
use miden_protocol::account::{Account, AccountCode, AccountId, AccountPatch};
use miden_protocol::asset::AssetVault;
Expand Down Expand Up @@ -38,7 +38,6 @@ use miden_standards::note::{NetworkAccountTarget, NoteExecutionHint};
use miden_tx::auth::BasicAuthenticator;
use miden_tx::{LocalTransactionProver, TransactionExecutor};
use tokio::sync::{Mutex, watch};
use tracing::{debug, error, info, warn};

use crate::config::MonitorConfig;
use crate::deploy::counter::COUNTER_SLOT_NAME;
Expand Down Expand Up @@ -271,30 +270,26 @@ impl IncrementService {
.await
.inspect_err(|e| {
error!(
e,
target: LOG_TARGET,
{
account.id = %self.tx.wallet_account.id(),
error = ?e,
},
"Failed to re-sync wallet account from RPC"
"Failed to re-sync wallet account from RPC",
account.id = self.tx.wallet_account.id()
);
})?
.context("wallet account not found on-chain during re-sync")
.inspect_err(|e| {
error!(
e,
target: LOG_TARGET,
{
account.id = %self.tx.wallet_account.id(),
error = ?e,
},
"Wallet account not found on-chain during re-sync"
"Wallet account not found on-chain during re-sync",
account.id = self.tx.wallet_account.id()
);
})?;

debug!(
target: LOG_TARGET,
{ account.id = %self.tx.wallet_account.id() },
"Wallet account re-synced from RPC"
"Wallet account re-synced from RPC",
account.id = self.tx.wallet_account.id()
);
self.tx.wallet_account = fresh_account;
Ok(())
Expand Down Expand Up @@ -406,9 +401,12 @@ impl IncrementService {

let block_height = self.submission_client.submit(&proven_tx, &tx_inputs).await?;

info!(target: LOG_TARGET, "Submitted proven transaction to RPC");

let tx_id = proven_tx.id().to_hex();
info!(
target: LOG_TARGET,
"Submitted proven transaction to RPC",
transaction.id = tx_id.as_str()
);

Ok((tx_id, account_patch, block_height))
}
Expand Down Expand Up @@ -445,7 +443,7 @@ impl Service for IncrementService {
guard.pending_started = Some(Instant::now());
},
Err(e) => {
error!(target: LOG_TARGET, error = ?e, "Failed to create and submit network note");
error!(&e, target: LOG_TARGET, "Failed to create and submit network note");
self.details.failure_count += 1;
self.failures.record_failure();
last_error = Some(format!("create/submit note failed: {e}"));
Expand All @@ -459,15 +457,15 @@ impl Service for IncrementService {
if !resynced_now && self.failures.should_regenerate() {
warn!(
target: LOG_TARGET,
consecutive_failures = self.failures.consecutive_failures,
"re-sync ineffective, regenerating accounts from scratch"
"re-sync ineffective, regenerating accounts from scratch",
counter.failures.consecutive = self.failures.consecutive_failures
);
self.failures.mark_regeneration_attempt();
match self.try_regenerate_accounts().await {
Ok(()) => self.failures.reset(),
Err(regen_err) => {
self.failures.mark_regeneration_failed();
error!(target: LOG_TARGET, error = ?regen_err, "Account regeneration failed");
error!(&regen_err, target: LOG_TARGET, "Account regeneration failed");
},
}
}
Expand Down Expand Up @@ -552,13 +550,11 @@ impl CounterTrackingService {

info!(
target: LOG_TARGET,
{
old.counter.id = %self.counter_account.id(),
new.counter.id = %reloaded.counter.id(),
old.wallet.id = %self.wallet_account.id(),
new.wallet.id = %reloaded.wallet.id(),
},
"monitor accounts changed, resetting tracking state",
counter.account.id.old = self.counter_account.id(),
counter.account.id.new = reloaded.counter.id(),
wallet.account.id.old = self.wallet_account.id(),
wallet.account.id.new = reloaded.wallet.id()
);
self.wallet_account = reloaded.wallet;
self.counter_account = reloaded.counter;
Expand Down Expand Up @@ -592,7 +588,7 @@ impl CounterTrackingService {
// Counter value not available yet, but not an error.
Ok(None) => return None,
Err(e) => {
error!(target: LOG_TARGET, error = ?e, "Failed to fetch counter value");
error!(&e, target: LOG_TARGET, "Failed to fetch counter value");
return Some(format!("fetch counter value failed: {e}"));
},
};
Expand All @@ -614,8 +610,8 @@ impl CounterTrackingService {
Ok(None) => {},
Err(e) => {
error!(
&e,
target: LOG_TARGET,
error = ?e,
"Failed to fetch expected wallet counter value"
);
last_error = Some(format!("fetch expected value failed: {e}"));
Expand Down Expand Up @@ -664,9 +660,10 @@ impl CounterTrackingService {
{
warn!(
target: LOG_TARGET,
timeout = ?self.config.counter_latency_timeout,
target_value = pending.target_value,
"Latency measurement timed out"
"Latency measurement timed out",
counter.latency.timeout_ms =
self.config.counter_latency_timeout.as_millis() as u64,
counter.value.target = pending.target_value
);
let mut guard = self.latency_state.lock().await;
if guard.pending.as_ref().map(|p| p.target_value) == Some(pending.target_value) {
Expand Down Expand Up @@ -767,18 +764,22 @@ async fn initialize_tracking_state(
Ok(Some(observed)) => {
details.current_value = Some(observed);
details.last_updated = Some(current_unix_timestamp_secs());
info!(target: LOG_TARGET, observed_value = observed, "Initialized counter tracking");
info!(
target: LOG_TARGET,
"Initialized counter tracking",
counter.value.observed = observed
);
},
Ok(None) => warn!(target: LOG_TARGET, "Counter account not found at init"),
Err(e) => error!(target: LOG_TARGET, error = ?e, "Failed to fetch initial counter value"),
Err(e) => error!(&e, target: LOG_TARGET, "Failed to fetch initial counter value"),
}

match fetch_slot_value(rpc_client, wallet_account.id(), WALLET_COUNTER_SLOT_NAME.as_str()).await
{
Ok(Some(expected)) => details.expected_value = Some(expected),
Ok(None) => {},
Err(e) => {
error!(target: LOG_TARGET, error = ?e, "Failed to fetch initial expected wallet value");
error!(&e, target: LOG_TARGET, "Failed to fetch initial expected wallet value");
},
}

Expand Down Expand Up @@ -858,9 +859,9 @@ fn update_expected_and_pending(
} else {
warn!(
target: LOG_TARGET,
expected_value = expected,
observed_value = observed_value,
"Expected counter value is less than current value, setting pending to 0"
"Expected counter value is less than current value, setting pending to 0",
counter.value.expected = expected,
counter.value.observed = observed_value
);
details.pending_increments = Some(0);
}
Expand Down Expand Up @@ -968,12 +969,10 @@ async fn fetch_wallet_account(
Ok(response) => response.into_inner(),
Err(e) => {
warn!(
&e,
target: LOG_TARGET,
{
account.id = %account_id,
error = %e,
},
"Failed to fetch wallet account via RPC"
"Failed to fetch wallet account via RPC",
account.id = account_id
);
return Ok(None);
},
Expand All @@ -983,8 +982,8 @@ async fn fetch_wallet_account(
if response.witness.is_some() {
info!(
target: LOG_TARGET,
{ account.id = %account_id },
"account found on-chain but cannot reconstruct full account from RPC response"
"account found on-chain but cannot reconstruct full account from RPC response",
account.id = account_id
);
}
return Ok(None);
Expand Down Expand Up @@ -1058,7 +1057,7 @@ async fn fetch_wallet_account(
expected_storage_commitment
);

info!(target: LOG_TARGET, { account.id = %account_id }, "Fetched wallet account from RPC");
info!(target: LOG_TARGET, "Fetched wallet account from RPC", account.id = account_id);
Ok(Some(account))
}

Expand Down
46 changes: 25 additions & 21 deletions bin/network-monitor/src/deploy/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ use miden_node_proto::generated::rpc::{
use miden_node_proto::generated::transaction::ProvenTransaction as ProtoProvenTransaction;
use miden_node_utils::retry;
use miden_node_utils::spawn::spawn_blocking_in_current_span;
use miden_node_utils::tracing::miden_instrument;
use miden_node_utils::tracing::{debug, info, miden_instrument, warn};
use miden_protocol::Word;
use miden_protocol::account::{
Account,
Expand Down Expand Up @@ -183,11 +183,11 @@ impl TransactionSubmissionClient {
})
.notify(|status: &anyhow::Error, _| {
stale_key.store(true, Ordering::Relaxed);
tracing::warn!(
warn!(
status,
target: COMPONENT,
%tx_id,
err = %status,
"Transaction inputs rejected as stale, refreshing the encryption key and retrying",
transaction.id = tx_id
);
})
.await;
Expand Down Expand Up @@ -277,11 +277,11 @@ pub async fn create_genesis_aware_rpc_client(
})
.retry(genesis_discovery_backoff())
.notify(|err: &anyhow::Error, sleep: Duration| {
tracing::warn!(
warn!(
err,
target: COMPONENT,
err = ?err,
sleep_ms = sleep.as_millis() as u64,
"RPC genesis discovery failed; retrying after backoff",
retry.delay_ms = sleep.as_millis() as u64
);
})
.await
Expand All @@ -296,7 +296,7 @@ pub async fn create_and_deploy_accounts(
submission_client: &TransactionSubmissionClient,
prover: &LocalTransactionProver,
) -> Result<DeployedMonitorAccounts> {
tracing::info!(target: LOG_TARGET, "Creating fresh monitor accounts");
info!(target: LOG_TARGET, "Creating fresh monitor accounts");

let mut rpc_client = submission_client.rpc_client();

Expand All @@ -314,7 +314,10 @@ pub async fn create_and_deploy_accounts(
let counter_anchor =
resolve_counter_anchor(&mut rpc_client, &genesis_header, &committed_counter).await?;

tracing::info!(target: LOG_TARGET, "Successfully created and deployed accounts");
info!(
target: LOG_TARGET,
"Successfully created and deployed accounts"
);

Ok(DeployedMonitorAccounts {
wallet: wallet_account,
Expand Down Expand Up @@ -397,26 +400,27 @@ async fn resolve_counter_anchor(
.await
{
Ok(Some(anchor)) => {
tracing::info!(
info!(
target: LOG_TARGET,
{
account.id = %committed_counter.id(),
block.number = %anchor.block_header.block_num(),
},
"Resolved counter FPI anchor"
"Resolved counter FPI anchor",
account.id = committed_counter.id(),
block.number = anchor.block_header.block_num()
);
return Ok(anchor);
},
Ok(None) => tracing::debug!(
Ok(None) => debug!(
target: LOG_TARGET,
{ account.id = %committed_counter.id(), attempt },
"Counter account not yet committed in the expected state; retrying"
"Counter account not yet committed in the expected state; retrying",
account.id = committed_counter.id(),
retry.attempt = attempt
),
Err(err) => {
tracing::debug!(
debug!(
&err,
target: LOG_TARGET,
{ account.id = %committed_counter.id(), attempt, error = ?err },
"Counter anchor resolution attempt failed; retrying"
"Counter anchor resolution attempt failed; retrying",
account.id = committed_counter.id(),
retry.attempt = attempt
);
last_error = Some(err);
},
Expand Down
Loading
Loading