From c7cc5cc49fae9657c970555df9c08b9c156d719d Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Thu, 9 Apr 2026 09:13:59 -0700 Subject: [PATCH 1/6] [telemetry] Add structured logging with span-based tracing MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Replaces the per-binary init_tracing_subscriber() boilerplate with a shared hashi-telemetry crate that auto-detects the log format via std::io::IsTerminal and honors RUST_LOG / RUST_LOG_JSON: - stderr is a terminal (local dev) → human format - stderr is a pipe (K8s pod) → JSON (for Loki) - RUST_LOG_JSON=1 / =0 → hard override, wins over auto-detect CI workflows that want human-readable output for pipe'd GitHub Actions runner stderr set RUST_LOG_JSON=0 at the workflow env level. .github/workflows/ci.yml does this for the hashi CI job. Instruments the main unit-of-work boundaries across the daemon: the gRPC handlers in bridge_service, deposit/withdrawal validation, every leader task (deposit processing, withdrawal approval/commitment/signing/confirmation fan-outs), the Bitcoin and Sui indexers, MPC run loops and handle_reconfig, every execute_* method in sui_tx_executor (with sui_digest recorded on the generic execute), and mpc::signing::sign so presig-reassignment logs carry their parent span. Service identification (hashi vs hashi-screener vs hashi-guardian vs hashi-monitor) is done via Kubernetes pod labels already injected by Promtail at ingest, not via a log-body field. --- .github/workflows/ci.yml | 4 + Cargo.lock | 13 ++ Cargo.toml | 2 +- crates/e2e-tests/Cargo.toml | 1 + crates/e2e-tests/src/main.rs | 9 +- crates/hashi-guardian/Cargo.toml | 1 + crates/hashi-guardian/src/main.rs | 26 +--- crates/hashi-monitor/Cargo.toml | 1 + crates/hashi-monitor/src/main.rs | 24 +--- crates/hashi-screener/Cargo.toml | 1 + crates/hashi-screener/src/main.rs | 19 +-- crates/hashi-telemetry/Cargo.toml | 9 ++ crates/hashi-telemetry/src/lib.rs | 176 ++++++++++++++++++++++++ crates/hashi/Cargo.toml | 1 + crates/hashi/src/btc_monitor/monitor.rs | 1 + crates/hashi/src/cli/mod.rs | 16 +-- crates/hashi/src/deposits.rs | 13 ++ crates/hashi/src/grpc/bridge_service.rs | 87 ++++++++---- crates/hashi/src/leader/mod.rs | 102 +++++++------- crates/hashi/src/main.rs | 19 +-- crates/hashi/src/mpc/service.rs | 4 + crates/hashi/src/mpc/signing.rs | 5 + crates/hashi/src/onchain/watcher.rs | 1 + crates/hashi/src/sui_tx_executor.rs | 90 ++++++++++++ crates/hashi/src/withdrawals.rs | 12 ++ docker/hashi-screener/Containerfile | 6 +- docker/hashi/Containerfile | 6 +- 27 files changed, 484 insertions(+), 165 deletions(-) create mode 100644 crates/hashi-telemetry/Cargo.toml create mode 100644 crates/hashi-telemetry/src/lib.rs diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index f90be8517..bbc2de48d 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -10,6 +10,10 @@ permissions: env: RUSTFLAGS: -Dwarnings + # Force human-readable log output even though stderr is a pipe in GitHub + # Actions runners. Any hashi binary invoked from this workflow uses + # hashi-telemetry, which would otherwise auto-detect JSON for non-TTY stderr. + RUST_LOG_JSON: "0" jobs: test: diff --git a/Cargo.lock b/Cargo.lock index 7f1a59a24..74b53f770 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2088,6 +2088,7 @@ dependencies = [ "futures", "hashi", "hashi-screener", + "hashi-telemetry", "hashi-types", "nix", "prometheus", @@ -2828,6 +2829,7 @@ dependencies = [ "fastcrypto-tbls", "fjall", "futures", + "hashi-telemetry", "hashi-types", "hex", "jiff", @@ -2882,6 +2884,7 @@ dependencies = [ "aws-sdk-s3", "aws-smithy-mocks", "bitcoin", + "hashi-telemetry", "hashi-types", "hpke", "k256", @@ -2905,6 +2908,7 @@ dependencies = [ "corepc-client", "e2e-tests", "hashi-guardian", + "hashi-telemetry", "hashi-types", "hex", "hpke", @@ -2928,6 +2932,7 @@ dependencies = [ "axum", "backon", "bitcoin", + "hashi-telemetry", "hashi-types", "lru", "prometheus", @@ -2946,6 +2951,14 @@ dependencies = [ "tracing-subscriber", ] +[[package]] +name = "hashi-telemetry" +version = "0.1.0" +dependencies = [ + "tracing", + "tracing-subscriber", +] + [[package]] name = "hashi-types" version = "0.0.0" diff --git a/Cargo.toml b/Cargo.toml index df100c1b2..ca41f1e6b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -43,7 +43,7 @@ tabled = "0.16" anyhow = "1.0.98" toml = "0.9.2" futures = "0.3.31" -tracing-subscriber = { version = "0.3.19", features = ["env-filter"] } +tracing-subscriber = { version = "0.3.19", features = ["env-filter", "json"] } # TODO: Switch back to a crates.io release once age 0.12+ is published. # We pin to this specific commit because age 0.11.x depends on i18n-embed-fl 0.9.x, # which has a non-determinism bug (HashMap iteration in the fl!() proc macro) that diff --git a/crates/e2e-tests/Cargo.toml b/crates/e2e-tests/Cargo.toml index 8dd15cd7d..8acaf5466 100644 --- a/crates/e2e-tests/Cargo.toml +++ b/crates/e2e-tests/Cargo.toml @@ -33,6 +33,7 @@ colored.workspace = true rand.workspace = true nix = { version = "0.26.4", features = ["signal"] } tracing-subscriber.workspace = true +hashi-telemetry = { path = "../hashi-telemetry" } [[bin]] name = "hashi-localnet" diff --git a/crates/e2e-tests/src/main.rs b/crates/e2e-tests/src/main.rs index 8f81443a4..ec44e3c13 100644 --- a/crates/e2e-tests/src/main.rs +++ b/crates/e2e-tests/src/main.rs @@ -279,13 +279,10 @@ async fn cmd_start( tracing::level_filters::LevelFilter::OFF }; - tracing_subscriber::fmt() - .with_env_filter( - tracing_subscriber::EnvFilter::builder() - .with_default_directive(default_level.into()) - .from_env_lossy(), - ) + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_default_level(default_level) .with_target(false) + .with_env() .init(); use std::io::Write; diff --git a/crates/hashi-guardian/Cargo.toml b/crates/hashi-guardian/Cargo.toml index a3a119969..59ad86667 100644 --- a/crates/hashi-guardian/Cargo.toml +++ b/crates/hashi-guardian/Cargo.toml @@ -11,6 +11,7 @@ serde.workspace = true serde_json.workspace = true tracing.workspace = true tracing-subscriber.workspace = true +hashi-telemetry = { path = "../hashi-telemetry" } tonic.workspace = true hashi-types = { path = "../hashi-types" } diff --git a/crates/hashi-guardian/src/main.rs b/crates/hashi-guardian/src/main.rs index 32512a924..a8292e96b 100644 --- a/crates/hashi-guardian/src/main.rs +++ b/crates/hashi-guardian/src/main.rs @@ -102,7 +102,10 @@ pub struct EphemeralKeyPairs { /// SETUP_MODE=false: all endpoints except setup_new_key are enabled. #[tokio::main] async fn main() -> Result<()> { - init_tracing_subscriber(true); + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_file_line(true) + .with_env() + .init(); // Check if SETUP_MODE is enabled (defaults to false) let setup_mode = std::env::var("SETUP_MODE") @@ -537,27 +540,6 @@ impl Enclave { } } -// --------------------------------- -// Tracing utilities -// --------------------------------- - -/// Initialize tracing subscriber with optional file/line number logging -pub fn init_tracing_subscriber(with_file_line: bool) { - let mut builder = tracing_subscriber::FmtSubscriber::builder().with_env_filter( - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::INFO.into()) - .from_env_lossy(), - ); - - if with_file_line { - builder = builder.with_file(true).with_line_number(true); - } - - let subscriber = builder.finish(); - tracing::subscriber::set_global_default(subscriber) - .expect("unable to initialize tracing subscriber"); -} - // --------------------------------- // Tests and related utilities // --------------------------------- diff --git a/crates/hashi-monitor/Cargo.toml b/crates/hashi-monitor/Cargo.toml index 95f7c4ef5..2c2edec8f 100644 --- a/crates/hashi-monitor/Cargo.toml +++ b/crates/hashi-monitor/Cargo.toml @@ -22,6 +22,7 @@ tokio.workspace = true tonic.workspace = true tracing.workspace = true tracing-subscriber.workspace = true +hashi-telemetry = { path = "../hashi-telemetry" } [dev-dependencies] e2e-tests = { path = "../e2e-tests" } diff --git a/crates/hashi-monitor/src/main.rs b/crates/hashi-monitor/src/main.rs index 3e900d9a9..4bbe6852f 100644 --- a/crates/hashi-monitor/src/main.rs +++ b/crates/hashi-monitor/src/main.rs @@ -51,7 +51,10 @@ enum Command { #[tokio::main] async fn main() -> anyhow::Result<()> { - init_tracing_subscriber(false); + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_target(false) + .with_env() + .init(); let cli = Cli::parse(); @@ -78,22 +81,3 @@ async fn main() -> anyhow::Result<()> { Ok(()) } - -pub fn init_tracing_subscriber(with_file_line: bool) { - let mut builder = tracing_subscriber::FmtSubscriber::builder().with_env_filter( - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::INFO.into()) - .from_env_lossy(), - ); - - if with_file_line { - builder = builder - .with_file(true) - .with_line_number(true) - .with_target(false); - } - - let subscriber = builder.finish(); - tracing::subscriber::set_global_default(subscriber) - .expect("unable to initialize tracing subscriber"); -} diff --git a/crates/hashi-screener/Cargo.toml b/crates/hashi-screener/Cargo.toml index 230dffb50..720a63059 100644 --- a/crates/hashi-screener/Cargo.toml +++ b/crates/hashi-screener/Cargo.toml @@ -11,6 +11,7 @@ thiserror.workspace = true tokio.workspace = true tracing.workspace = true tracing-subscriber.workspace = true +hashi-telemetry = { path = "../hashi-telemetry" } prometheus.workspace = true axum.workspace = true sui-http.workspace = true diff --git a/crates/hashi-screener/src/main.rs b/crates/hashi-screener/src/main.rs index fb16c3ab0..2c8ea3456 100644 --- a/crates/hashi-screener/src/main.rs +++ b/crates/hashi-screener/src/main.rs @@ -226,20 +226,6 @@ impl ScreenerService for ScreenerServiceImpl { } } -fn init_tracing_subscriber() { - let subscriber = tracing_subscriber::FmtSubscriber::builder() - .with_env_filter( - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::INFO.into()) - .from_env_lossy(), - ) - .with_file(true) - .with_line_number(true) - .finish(); - tracing::subscriber::set_global_default(subscriber) - .expect("unable to initialize tracing subscriber"); -} - fn start_metrics_server(registry: prometheus::Registry) -> sui_http::ServerHandle { let addr: SocketAddr = "0.0.0.0:9184".parse().unwrap(); info!("Prometheus metrics server listening on {}", addr); @@ -266,7 +252,10 @@ async fn metrics_handler( #[tokio::main] async fn main() -> Result<()> { - init_tracing_subscriber(); + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_file_line(true) + .with_env() + .init(); let api_key = env::var("MERKLE_SCIENCE_API_KEY") .map_err(|_| anyhow::anyhow!("MERKLE_SCIENCE_API_KEY environment variable is not set"))?; diff --git a/crates/hashi-telemetry/Cargo.toml b/crates/hashi-telemetry/Cargo.toml new file mode 100644 index 000000000..1dad54840 --- /dev/null +++ b/crates/hashi-telemetry/Cargo.toml @@ -0,0 +1,9 @@ +[package] +name = "hashi-telemetry" +version = "0.1.0" +edition = "2024" +publish = false + +[dependencies] +tracing.workspace = true +tracing-subscriber.workspace = true diff --git a/crates/hashi-telemetry/src/lib.rs b/crates/hashi-telemetry/src/lib.rs new file mode 100644 index 000000000..71ee52d47 --- /dev/null +++ b/crates/hashi-telemetry/src/lib.rs @@ -0,0 +1,176 @@ +// Copyright (c) Mysten Labs, Inc. +// SPDX-License-Identifier: Apache-2.0 + +//! Shared telemetry configuration for all hashi binaries. +//! +//! Provides a [`TelemetryConfig`] builder that sets up a `tracing` subscriber with: +//! - **JSON output** for production (Kubernetes / Grafana / Loki) +//! - **Human-readable TTY output** for local development +//! - Automatic format detection based on [`std::io::IsTerminal`] for stderr: +//! stderr is a terminal → human, stderr is a pipe/redirect → JSON. +//! - `RUST_LOG` environment variable support via [`tracing_subscriber::EnvFilter`] +//! - `RUST_LOG_JSON=1`/`0` hard override. CI workflows that want human-readable +//! logs in pipe'd GitHub Actions output should set `RUST_LOG_JSON=0` in the +//! workflow env block. +//! +//! Service-level identification (filtering Loki by `hashi` vs `hashi-screener` +//! etc.) is delegated to Kubernetes pod labels injected by Promtail/Alloy at +//! ingest time, not written into the log body. Use `{app="hashi"}` in LogQL. + +use std::io::IsTerminal; +use std::io::stderr; + +use tracing::level_filters::LevelFilter; +use tracing_subscriber::EnvFilter; +use tracing_subscriber::Layer; +use tracing_subscriber::layer::SubscriberExt; +use tracing_subscriber::util::SubscriberInitExt; + +/// Configuration for the tracing subscriber. +/// +/// # Examples +/// +/// ```no_run +/// use hashi_telemetry::TelemetryConfig; +/// +/// // Production server: auto-detect JSON vs TTY, INFO default +/// let _guard = TelemetryConfig::new() +/// .with_file_line(true) +/// .with_env() +/// .init(); +/// +/// // CLI tool: WARN default, no target, verbose override +/// let _guard = TelemetryConfig::new() +/// .with_default_level(tracing::level_filters::LevelFilter::WARN) +/// .with_target(false) +/// .with_env() +/// .init(); +/// ``` +pub struct TelemetryConfig { + /// Base log level when `RUST_LOG` is not set. Default: `INFO`. + default_level: LevelFilter, + /// Force JSON (`Some(true)`) or TTY (`Some(false)`) output. + /// `None` means auto-detect — see [`TelemetryConfig::init`]. + json: Option, + /// Show `file:line` in log output. Default: `false`. + file_line: bool, + /// Show module target path in log output. Default: `true`. + target: bool, +} + +impl Default for TelemetryConfig { + fn default() -> Self { + Self::new() + } +} + +impl TelemetryConfig { + /// Create a new config with sensible defaults (INFO level, auto-detect format). + pub fn new() -> Self { + Self { + default_level: LevelFilter::INFO, + json: None, + file_line: false, + target: true, + } + } + + /// Set the default log level (used when `RUST_LOG` is not set). + pub fn with_default_level(mut self, level: LevelFilter) -> Self { + self.default_level = level; + self + } + + /// Force JSON (`true`) or TTY (`false`) output, overriding auto-detection. + pub fn with_json(mut self, json: bool) -> Self { + self.json = Some(json); + self + } + + /// Show `file:line` in log output. + pub fn with_file_line(mut self, enabled: bool) -> Self { + self.file_line = enabled; + self + } + + /// Show module target path in log output. + pub fn with_target(mut self, enabled: bool) -> Self { + self.target = enabled; + self + } + + /// Read configuration overrides from environment variables. + /// + /// `RUST_LOG_JSON`: + /// - `0`, `false`, `no` (case-insensitive) → force JSON off, use the + /// human-readable format even inside a pipe or container. + /// - any other non-empty value → force JSON on, overriding auto-detection. + /// - unset → leave the auto-detected choice in place. + pub fn with_env(mut self) -> Self { + if let Ok(value) = std::env::var("RUST_LOG_JSON") { + let normalized = value.trim().to_ascii_lowercase(); + self.json = match normalized.as_str() { + "0" | "false" | "no" => Some(false), + _ => Some(true), + }; + } + self + } + + /// Build and install the tracing subscriber. + /// + /// Auto-detects the format when neither [`TelemetryConfig::with_json`] nor + /// `RUST_LOG_JSON` is set: stderr is a terminal → human format; stderr is + /// a pipe / redirect → JSON. + /// + /// Returns a [`TelemetryGuard`] that must be held alive for the duration of the program. + pub fn init(self) -> TelemetryGuard { + let use_json = match self.json { + Some(true) => true, + Some(false) => false, + None => !stderr().is_terminal(), + }; + + let env_filter = EnvFilter::builder() + .with_default_directive(self.default_level.into()) + .from_env_lossy(); + + if use_json { + // NOTE: JSON output always includes file/line regardless of the + // `with_file_line` setting. In production (Kubernetes → Loki) we + // always want the exact source location on every event for + // debuggability, and the cost of the extra fields on structured + // output is negligible. The `with_file_line` builder setting only + // affects the TTY branch below, where it is off by default to + // keep local dev output uncluttered. + let fmt_layer = tracing_subscriber::fmt::layer() + .with_file(true) + .with_line_number(true) + .with_target(self.target) + .json() + .with_filter(env_filter); + + tracing_subscriber::registry().with(fmt_layer).init(); + } else { + let fmt_layer = tracing_subscriber::fmt::layer() + .with_file(self.file_line) + .with_line_number(self.file_line) + .with_target(self.target) + .with_ansi(stderr().is_terminal()) + .with_filter(env_filter); + + tracing_subscriber::registry().with(fmt_layer).init(); + } + + TelemetryGuard { _private: () } + } +} + +/// Guard that must be held alive for the duration of the program. +/// +/// Future additions (non-blocking writer flush, OpenTelemetry shutdown) +/// will be handled in its `Drop` implementation. +#[must_use = "dropping the guard immediately will lose buffered log output"] +pub struct TelemetryGuard { + _private: (), +} diff --git a/crates/hashi/Cargo.toml b/crates/hashi/Cargo.toml index 5a8cb3e61..edc2c1b97 100644 --- a/crates/hashi/Cargo.toml +++ b/crates/hashi/Cargo.toml @@ -35,6 +35,7 @@ tower.workspace = true tokio.workspace = true prometheus.workspace = true tracing.workspace = true +hashi-telemetry = { path = "../hashi-telemetry" } bin-version.workspace = true prometheus-closure-metric.workspace = true diff --git a/crates/hashi/src/btc_monitor/monitor.rs b/crates/hashi/src/btc_monitor/monitor.rs index a68c93483..0966e74f8 100644 --- a/crates/hashi/src/btc_monitor/monitor.rs +++ b/crates/hashi/src/btc_monitor/monitor.rs @@ -226,6 +226,7 @@ impl Monitor { } /// Run the main event loop, returning the reason it exited. + #[tracing::instrument(name = "btc_monitor", skip_all)] async fn run_event_loop( &mut self, kyoto_client: &mut kyoto::Client, diff --git a/crates/hashi/src/cli/mod.rs b/crates/hashi/src/cli/mod.rs index 9a67df4e1..ceb434837 100644 --- a/crates/hashi/src/cli/mod.rs +++ b/crates/hashi/src/cli/mod.rs @@ -668,19 +668,17 @@ fn parse_metadata(args: Vec) -> Vec<(String, String)> { } fn init_tracing(verbose: bool) { - let filter = if verbose { - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::DEBUG.into()) - .from_env_lossy() + let level = if verbose { + tracing::level_filters::LevelFilter::DEBUG } else { - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::WARN.into()) - .from_env_lossy() + tracing::level_filters::LevelFilter::WARN }; - tracing_subscriber::fmt() - .with_env_filter(filter) + // Guard is intentionally leaked — the CLI runs to completion in main(). + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_default_level(level) .with_target(false) + .with_env() .init(); } diff --git a/crates/hashi/src/deposits.rs b/crates/hashi/src/deposits.rs index 082c67aeb..2652b2a5c 100644 --- a/crates/hashi/src/deposits.rs +++ b/crates/hashi/src/deposits.rs @@ -46,6 +46,7 @@ pub fn derive_deposit_address( } impl Hashi { + #[tracing::instrument(level = "info", skip_all, fields(deposit_id = %deposit_request.id))] pub async fn validate_and_sign_deposit_confirmation( &self, deposit_request: &DepositRequest, @@ -54,6 +55,7 @@ impl Hashi { self.sign_deposit_confirmation(deposit_request) } + #[tracing::instrument(level = "debug", skip_all, fields(deposit_id = %deposit_request.id))] pub async fn validate_deposit_request( &self, deposit_request: &DepositRequest, @@ -67,6 +69,7 @@ impl Hashi { /// Run AML/Sanctions checks for the deposit request. /// If no screener client is configured, checks are skipped. + #[tracing::instrument(level = "debug", skip_all, fields(deposit_id = %deposit_request.id))] async fn screen_deposit( &self, deposit_request: &DepositRequest, @@ -104,6 +107,7 @@ impl Hashi { } /// Validate that the deposit request exists on Sui + #[tracing::instrument(level = "debug", skip_all, fields(deposit_id = %deposit_request.id))] fn validate_deposit_request_on_sui( &self, deposit_request: &DepositRequest, @@ -143,6 +147,15 @@ impl Hashi { } /// Validate that there is a txout on Bitcoin that matches the deposit request + #[tracing::instrument( + level = "debug", + skip_all, + fields( + deposit_id = %deposit_request.id, + bitcoin_txid = %deposit_request.utxo.id.txid, + vout = deposit_request.utxo.id.vout, + ), + )] async fn validate_deposit_request_on_bitcoin( &self, deposit_request: &DepositRequest, diff --git a/crates/hashi/src/grpc/bridge_service.rs b/crates/hashi/src/grpc/bridge_service.rs index 66a84f3ab..1772682a8 100644 --- a/crates/hashi/src/grpc/bridge_service.rs +++ b/crates/hashi/src/grpc/bridge_service.rs @@ -45,20 +45,26 @@ impl BridgeService for HttpService { } /// Validate and sign a confirmation of a bitcoin deposit request. + #[tracing::instrument( + level = "info", + skip_all, + fields(deposit_id = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_deposit_confirmation( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let deposit_request = parse_deposit_request(request.get_ref()) .map_err(|e| Status::invalid_argument(e.to_string()))?; + tracing::Span::current().record("deposit_id", tracing::field::display(&deposit_request.id)); let member_signature = self .inner .validate_and_sign_deposit_confirmation(&deposit_request) .await .map_err(|e| Status::failed_precondition(e.to_string()))?; tracing::info!( - deposit_request_id = %deposit_request.id, utxo_txid = %deposit_request.utxo.id.txid, utxo_vout = deposit_request.utxo.id.vout, amount = deposit_request.utxo.amount, @@ -70,42 +76,53 @@ impl BridgeService for HttpService { } /// Step 1: Validate and sign approval for a batch of unapproved withdrawal requests. + #[tracing::instrument( + level = "info", + skip_all, + fields(request_id = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_withdrawal_request_approval( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let approval = parse_withdrawal_request_approval(request.get_ref()) .map_err(|e| Status::invalid_argument(e.to_string()))?; + tracing::Span::current() + .record("request_id", tracing::field::display(&approval.request_id)); let member_signature = self .inner .validate_and_sign_withdrawal_request_approval(&approval) .await .map_err(|e| Status::failed_precondition(e.to_string()))?; - tracing::info!( - request_id = %approval.request_id, - "Signed withdrawal request approval", - ); + tracing::info!("Signed withdrawal request approval"); Ok(Response::new(SignWithdrawalRequestApprovalResponse { member_signature: Some(member_signature), })) } /// Step 2: Validate and sign a proposed withdrawal transaction construction. + #[tracing::instrument( + level = "info", + skip_all, + fields(bitcoin_txid = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_withdrawal_tx_construction( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let approval = parse_withdrawal_tx_commitment(request.get_ref()) .map_err(|e| Status::invalid_argument(e.to_string()))?; + tracing::Span::current().record("bitcoin_txid", tracing::field::display(&approval.txid)); let member_signature = self .inner .validate_and_sign_withdrawal_tx_commitment(&approval) .await .map_err(|e| Status::failed_precondition(e.to_string()))?; tracing::info!( - txid = %approval.txid, requests = approval.request_ids.len(), "Signed withdrawal tx construction", ); @@ -114,23 +131,33 @@ impl BridgeService for HttpService { })) } + #[tracing::instrument( + level = "info", + skip_all, + fields(withdrawal_txn_id = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_withdrawal_transaction( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let withdrawal_txn_id = Address::from_bytes(&request.get_ref().withdrawal_txn_id) .map_err(|e| Status::invalid_argument(format!("invalid withdrawal_txn_id: {e}")))?; - tracing::info!(withdrawal_txn_id = %withdrawal_txn_id, "sign_withdrawal_transaction called"); + tracing::Span::current().record( + "withdrawal_txn_id", + tracing::field::display(&withdrawal_txn_id), + ); + tracing::info!("sign_withdrawal_transaction called"); let signatures = self .inner .validate_and_sign_withdrawal_tx(&withdrawal_txn_id) .await .map_err(|e| { - tracing::error!(withdrawal_txn_id = %withdrawal_txn_id, "sign_withdrawal_transaction failed: {e}"); + tracing::error!("sign_withdrawal_transaction failed: {e}"); Status::failed_precondition(e.to_string()) })?; - tracing::info!(withdrawal_txn_id = %withdrawal_txn_id, "sign_withdrawal_transaction succeeded"); + tracing::info!("sign_withdrawal_transaction succeeded"); Ok(Response::new(SignWithdrawalTransactionResponse { signatures_by_input: signatures .iter() @@ -140,41 +167,55 @@ impl BridgeService for HttpService { } /// Step 3: Validate and sign the BLS certificate over witness signatures. + #[tracing::instrument( + level = "info", + skip_all, + fields(withdrawal_id = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_withdrawal_tx_signing( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let message = parse_withdrawal_tx_signing(request.get_ref()) .map_err(|e| Status::invalid_argument(e.to_string()))?; + tracing::Span::current().record( + "withdrawal_id", + tracing::field::display(&message.withdrawal_id), + ); let member_signature = self .inner .validate_and_sign_withdrawal_tx_signing(&message) .map_err(|e| Status::failed_precondition(e.to_string()))?; - tracing::info!( - withdrawal_id = %message.withdrawal_id, - "Signed withdrawal tx signing", - ); + tracing::info!("Signed withdrawal tx signing"); Ok(Response::new(SignWithdrawalTxSigningResponse { member_signature: Some(member_signature), })) } + #[tracing::instrument( + level = "info", + skip_all, + fields(withdrawal_txn_id = tracing::field::Empty, caller = tracing::field::Empty), + )] async fn sign_withdrawal_confirmation( &self, request: Request, ) -> Result, Status> { - authenticate_caller(&request)?; + let caller = authenticate_caller(&request)?; + tracing::Span::current().record("caller", tracing::field::display(&caller)); let withdrawal_txn_id = Address::from_bytes(&request.get_ref().withdrawal_txn_id) .map_err(|e| Status::invalid_argument(format!("invalid withdrawal_txn_id: {e}")))?; + tracing::Span::current().record( + "withdrawal_txn_id", + tracing::field::display(&withdrawal_txn_id), + ); let member_signature = self .inner .sign_withdrawal_confirmation(&withdrawal_txn_id) .map_err(|e| Status::failed_precondition(e.to_string()))?; - tracing::info!( - withdrawal_txn_id = %withdrawal_txn_id, - "Signed withdrawal confirmation", - ); + tracing::info!("Signed withdrawal confirmation"); Ok(Response::new(SignWithdrawalConfirmationResponse { member_signature: Some(member_signature), })) diff --git a/crates/hashi/src/leader/mod.rs b/crates/hashi/src/leader/mod.rs index eb288ffd8..34f1fa00b 100644 --- a/crates/hashi/src/leader/mod.rs +++ b/crates/hashi/src/leader/mod.rs @@ -98,6 +98,7 @@ impl LeaderService { }) } + #[tracing::instrument(name = "leader", skip_all)] async fn run(mut self) { info!("Starting leader service"); @@ -345,22 +346,23 @@ impl LeaderService { self.check_delete_expired_deposit_requests(&deposit_requests, checkpoint_timestamp_ms); } + #[tracing::instrument(level = "info", skip_all, fields(deposit_id = %deposit_request.id))] async fn process_deposit_request( inner: Arc, deposit_request: DepositRequest, ) -> anyhow::Result<()> { - info!(deposit_request_id = %deposit_request.id, "Processing deposit request"); + info!("Processing deposit request"); // Validate deposit_request before asking for signatures inner .validate_deposit_request(&deposit_request) .await .map_err(|e| { - debug!(request_id = ?deposit_request.id, "Deposit validation failed: {e}"); + debug!("Deposit validation failed: {e}"); anyhow::anyhow!(e) })?; - info!(deposit_request_id = %deposit_request.id, "Deposit request validated successfully"); + info!("Deposit request validated successfully"); let proto_request = deposit_request_to_proto(&deposit_request); let members = inner @@ -394,7 +396,7 @@ impl LeaderService { while let Some(result) = sig_tasks.join_next().await { let Ok(Some(sig)) = result else { continue }; if let Err(e) = aggregator.add_signature(sig) { - error!(deposit_request_id = %deposit_request.id, "Failed to add deposit signature: {e}"); + error!("Failed to add deposit signature: {e}"); } if aggregator.weight() >= required_weight { break; @@ -420,10 +422,10 @@ impl LeaderService { .with_label_values(&["confirm_deposit", "success"]) .inc(); inner.metrics.deposits_confirmed_total.inc(); - info!(deposit_request_id = %deposit_request.id, "Successfully submitted deposit confirmation"); + info!("Successfully submitted deposit confirmation"); }) .inspect_err(|e| { - error!(deposit_request_id = %deposit_request.id, "Failed to submit deposit confirmation: {e}"); + error!("Failed to submit deposit confirmation: {e}"); inner .metrics .sui_tx_submissions_total @@ -433,16 +435,14 @@ impl LeaderService { Ok(()) } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_deposit_confirmation_signature( inner: &Arc, proto_request: SignDepositConfirmationRequest, member: &CommitteeMember, ) -> Option { let validator_address = member.validator_address(); - trace!( - "Requesting deposit confirmation signature from {}", - validator_address - ); + trace!("Requesting deposit confirmation signature"); let mut rpc_client = inner .onchain_state() @@ -550,6 +550,7 @@ impl LeaderService { })); } + #[tracing::instrument(level = "info", skip_all, fields(batch_size = to_process.len()))] async fn process_unapproved_withdrawal_requests_task( inner: Arc, retry_tracker: RetryTracker, @@ -637,10 +638,7 @@ impl LeaderService { retry_tracker.record_failure(kind, request_id, checkpoint_timestamp_ms); } if let Err(err) = &result { - error!( - withdrawal_request_id = %request_id, - "Withdrawal approval failed: {err:#}" - ); + error!(request_id = %request_id, "Withdrawal approval failed: {err:#}"); } (request_id, result) @@ -666,6 +664,7 @@ impl LeaderService { Ok(()) } + #[tracing::instrument(level = "info", skip_all, fields(request_id = %request.id))] async fn process_unapproved_withdrawal_request( inner: Arc, retry_tracker: RetryTracker, @@ -705,7 +704,7 @@ impl LeaderService { let mut aggregator = BlsSignatureAggregator::new(committee, approval); if let Err(e) = aggregator.add_signature(local_sig) { - error!(withdrawal_request_id = %request.id, "Failed to add local approval signature: {e}"); + error!("Failed to add local approval signature: {e}"); } // Fan out signature requests to remote members in parallel. @@ -726,7 +725,7 @@ impl LeaderService { while let Some(result) = sig_tasks.join_next().await { let Ok(Some(sig)) = result else { continue }; if let Err(e) = aggregator.add_signature(sig) { - error!(withdrawal_request_id = %request.id, "Failed to add approval signature: {e}"); + error!("Failed to add approval signature: {e}"); } if aggregator.weight() >= required_weight { break; @@ -745,14 +744,14 @@ impl LeaderService { request.id, checkpoint_timestamp_ms, ); - error!(withdrawal_request_id = %request.id, "Insufficient approval signatures: weight {weight} < {required_weight}"); + error!("Insufficient approval signatures: weight {weight} < {required_weight}"); return Ok(None); } match aggregator.finish() { Ok(signed) => Ok(Some((request.id, signed.committee_signature().clone()))), Err(e) => { - error!(withdrawal_request_id = %request.id, "Failed to build approval certificate: {e}"); + error!("Failed to build approval certificate: {e}"); Ok(None) } } @@ -917,6 +916,7 @@ impl LeaderService { })); } + #[tracing::instrument(level = "info", skip_all, fields(batch_size = requests.len()))] async fn process_approved_withdrawal_request_batch( inner: Arc, retry_tracker: GlobalRetryTracker, @@ -1102,6 +1102,7 @@ impl LeaderService { } } + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_txn_id = %txn.id))] async fn process_unsigned_withdrawal_txn( inner: Arc, txn: WithdrawalTransaction, @@ -1112,7 +1113,6 @@ impl LeaderService { let current_epoch = inner.onchain_state().epoch(); if txn.epoch != current_epoch { info!( - withdrawal_txn_id = %txn.id, "Withdrawal transaction from epoch {} (current {}), reassigning presig indices", txn.epoch, current_epoch, ); @@ -1120,14 +1120,11 @@ impl LeaderService { executor .execute_allocate_presigs_for_withdrawal_txn(txn.id) .await?; - info!( - withdrawal_txn_id = %txn.id, - "Presig indices reassigned, will sign on next checkpoint" - ); + info!("Presig indices reassigned, will sign on next checkpoint"); // Return and let the next checkpoint iteration pick up the updated state. return Ok(()); } - info!(withdrawal_txn_id = %txn.id, "MPC signing withdrawal transaction"); + info!("MPC signing withdrawal transaction"); let members = inner .onchain_state() @@ -1267,25 +1264,33 @@ impl LeaderService { /// Check BTC tx status, broadcast/re-broadcast if needed, confirm when /// enough BTC confirmations are reached. + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_txn_id = %txn.id, bitcoin_txid))] async fn handle_signed_withdrawal( inner: Arc, txn: WithdrawalTransaction, ) -> anyhow::Result<()> { let confirmation_threshold = inner.onchain_state().bitcoin_confirmation_threshold(); let txid: bitcoin::Txid = txn.txid.into(); + tracing::Span::current().record("bitcoin_txid", tracing::field::display(&txid)); match inner.btc_monitor().get_transaction_status(txid).await { Ok(TxStatus::Confirmed { confirmations }) if confirmations >= confirmation_threshold => { - info!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, confirmations, "Withdrawal tx confirmed, proceeding to on-chain confirmation"); + info!( + confirmations, + "Withdrawal tx confirmed, proceeding to on-chain confirmation" + ); Self::confirm_withdrawal_on_sui(&inner, &txn).await?; } Ok(TxStatus::Confirmed { confirmations }) => { - debug!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, confirmations, confirmation_threshold, "Withdrawal tx waiting for more confirmations"); + debug!( + confirmations, + confirmation_threshold, "Withdrawal tx waiting for more confirmations" + ); } Ok(TxStatus::InMempool) => { - debug!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, "Withdrawal tx in mempool, waiting for confirmations"); + debug!("Withdrawal tx in mempool, waiting for confirmations"); } Ok(TxStatus::NotFound) => { Self::rebuild_and_broadcast_withdrawal_btc_tx(&inner, &txn, txid).await; @@ -1302,27 +1307,28 @@ impl LeaderService { /// Rebuild a fully signed Bitcoin transaction from on-chain WithdrawalTransaction /// data (stored witness signatures) and broadcast it to the Bitcoin network. + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid))] async fn rebuild_and_broadcast_withdrawal_btc_tx( inner: &Arc, txn: &WithdrawalTransaction, txid: bitcoin::Txid, ) { - warn!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, "Withdrawal tx not found, re-broadcasting from on-chain signatures"); + warn!("Withdrawal tx not found, re-broadcasting from on-chain signatures"); let tx = match Self::rebuild_signed_tx_from_onchain(inner, txn) { Ok(tx) => tx, Err(e) => { - error!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, "Failed to rebuild signed withdrawal tx: {e}"); + error!("Failed to rebuild signed withdrawal tx: {e}"); return; } }; match inner.btc_monitor().broadcast_transaction(tx).await { Ok(()) => { - info!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, "Re-broadcast withdrawal tx"); + info!("Re-broadcast withdrawal tx"); } Err(e) => { - error!(withdrawal_txn_id = %txn.id, bitcoin_txid = %txid, "Failed to re-broadcast withdrawal tx: {e}"); + error!("Failed to re-broadcast withdrawal tx: {e}"); } } } @@ -1369,6 +1375,7 @@ impl LeaderService { Ok(tx) } + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_txn_id = %txn.id))] async fn confirm_withdrawal_on_sui( inner: &Arc, txn: &WithdrawalTransaction, @@ -1402,6 +1409,7 @@ impl LeaderService { Ok(()) } + #[tracing::instrument(level = "debug", skip_all, fields(withdrawal_txn_id = %withdrawal_txn_id))] async fn collect_withdrawal_confirmation_signature( inner: &Arc, withdrawal_txn_id: Address, @@ -1431,7 +1439,7 @@ impl LeaderService { while let Some(result) = sig_tasks.join_next().await { let Ok(Some(sig)) = result else { continue }; if let Err(e) = aggregator.add_signature(sig) { - error!(withdrawal_txn_id = %withdrawal_txn_id, "Failed to add withdrawal confirmation signature: {e}"); + error!("Failed to add withdrawal confirmation signature: {e}"); } if aggregator.weight() >= required_weight { break; @@ -1449,16 +1457,14 @@ impl LeaderService { Ok(aggregator.finish()?.into_parts().0) } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_withdrawal_tx_commitment_signature( inner: &Arc, proto_request: SignWithdrawalTxConstructionRequest, member: &CommitteeMember, ) -> Option { let validator_address = member.validator_address(); - trace!( - "Requesting withdrawal approval signature from {}", - validator_address - ); + trace!("Requesting withdrawal tx commitment signature"); let mut rpc_client = inner .onchain_state() @@ -1501,16 +1507,14 @@ impl LeaderService { .ok() } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_withdrawal_approval_signature( inner: &Arc, proto_request: SignWithdrawalRequestApprovalRequest, member: &CommitteeMember, ) -> Option { let validator_address = member.validator_address(); - trace!( - "Requesting withdrawal request approval signature from {}", - validator_address - ); + trace!("Requesting withdrawal request approval signature"); let mut rpc_client = inner .onchain_state() @@ -1553,16 +1557,14 @@ impl LeaderService { .ok() } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_withdrawal_tx_signing_signature( inner: &Arc, proto_request: SignWithdrawalTxSigningRequest, member: &CommitteeMember, ) -> Option { let validator_address = member.validator_address(); - trace!( - "Requesting withdrawal tx signing signature from {}", - validator_address - ); + trace!("Requesting withdrawal tx signing signature"); let mut rpc_client = inner .onchain_state() @@ -1605,16 +1607,14 @@ impl LeaderService { .ok() } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_withdrawal_tx_signature( inner: &Arc, withdrawal_txn_id: &Address, member: &CommitteeMember, ) -> anyhow::Result> { let validator_address = member.validator_address(); - trace!( - "Requesting withdrawal tx signature from {}", - validator_address - ); + trace!("Requesting withdrawal tx signature"); let mut rpc_client = inner .onchain_state() @@ -1688,16 +1688,14 @@ impl LeaderService { } } + #[tracing::instrument(level = "debug", skip_all, fields(validator = %member.validator_address()))] async fn request_withdrawal_confirmation_signature( inner: &Arc, withdrawal_txn_id: Address, member: &CommitteeMember, ) -> Option { let validator_address = member.validator_address(); - trace!( - "Requesting withdrawal confirmation signature from {}", - validator_address - ); + trace!("Requesting withdrawal confirmation signature"); let mut rpc_client = inner .onchain_state() diff --git a/crates/hashi/src/main.rs b/crates/hashi/src/main.rs index a7badceb9..d7ba555f1 100644 --- a/crates/hashi/src/main.rs +++ b/crates/hashi/src/main.rs @@ -158,7 +158,10 @@ async fn main() -> anyhow::Result<()> { } async fn run_server(config_path: Option) -> anyhow::Result<()> { - init_tracing_subscriber(); + let _guard = hashi_telemetry::TelemetryConfig::new() + .with_file_line(true) + .with_env() + .init(); tracing::info!("welcome to hashi"); @@ -193,17 +196,3 @@ async fn run_server(config_path: Option) -> anyhow::Result<( tracing::info!("hashi shutting down; goodbye"); Ok(()) } - -fn init_tracing_subscriber() { - let subscriber = ::tracing_subscriber::FmtSubscriber::builder() - .with_env_filter( - tracing_subscriber::EnvFilter::builder() - .with_default_directive(tracing::level_filters::LevelFilter::INFO.into()) - .from_env_lossy(), - ) - .with_file(true) - .with_line_number(true) - .finish(); - ::tracing::subscriber::set_global_default(subscriber) - .expect("unable to initialize tracing subscriber"); -} diff --git a/crates/hashi/src/mpc/service.rs b/crates/hashi/src/mpc/service.rs index 34d853fd1..f2a9e5985 100644 --- a/crates/hashi/src/mpc/service.rs +++ b/crates/hashi/src/mpc/service.rs @@ -102,6 +102,7 @@ impl MpcService { }) } + #[tracing::instrument(name = "mpc_service", skip_all)] async fn run(mut self) { let pending = self.get_pending_epoch_change(); let is_in_committee = self.inner.is_in_current_committee(); @@ -282,6 +283,7 @@ impl MpcService { Ok(output) } + #[tracing::instrument(level = "info", skip_all, fields(target_epoch))] async fn run_dkg(&self, target_epoch: u64) -> anyhow::Result { let onchain_state = self.inner.onchain_state().clone(); let mpc_manager = self @@ -531,6 +533,7 @@ impl MpcService { } } + #[tracing::instrument(level = "info", skip_all, fields(target_epoch))] async fn handle_reconfig(&self, target_epoch: u64) { let run_dkg = self .inner @@ -645,6 +648,7 @@ impl MpcService { Ok(()) } + #[tracing::instrument(level = "info", skip_all, fields(target_epoch))] async fn run_key_rotation(&self, target_epoch: u64) -> anyhow::Result { let onchain_state = self.inner.onchain_state().clone(); let mpc_manager = self diff --git a/crates/hashi/src/mpc/signing.rs b/crates/hashi/src/mpc/signing.rs index 8f3c45c68..eafc2b568 100644 --- a/crates/hashi/src/mpc/signing.rs +++ b/crates/hashi/src/mpc/signing.rs @@ -184,6 +184,11 @@ impl SigningManager { } #[allow(clippy::too_many_arguments)] + #[tracing::instrument( + level = "info", + skip_all, + fields(sui_request_id = %sui_request_id, global_presig_index), + )] pub async fn sign( signing_manager: &Arc>, p2p_channel: &impl P2PChannel, diff --git a/crates/hashi/src/onchain/watcher.rs b/crates/hashi/src/onchain/watcher.rs index 21961041e..3e88eb2fc 100644 --- a/crates/hashi/src/onchain/watcher.rs +++ b/crates/hashi/src/onchain/watcher.rs @@ -27,6 +27,7 @@ use crate::onchain::types::ProposalType; use crate::onchain::types::WithdrawalRequest; use hashi_types::move_types::HashiEvent; +#[tracing::instrument(name = "watcher", skip_all)] pub async fn watcher(mut client: Client, state: OnchainState, metrics: Option>) { let subscription_read_mask = FieldMask::from_paths([ Checkpoint::path_builder().sequence_number(), diff --git a/crates/hashi/src/sui_tx_executor.rs b/crates/hashi/src/sui_tx_executor.rs index 873a5cb6a..4e9775760 100644 --- a/crates/hashi/src/sui_tx_executor.rs +++ b/crates/hashi/src/sui_tx_executor.rs @@ -260,6 +260,11 @@ impl SuiTxExecutor { /// and resolving object versions/digests automatically. /// /// Note: The builder is consumed because `TransactionBuilder::build()` takes ownership. + #[tracing::instrument( + level = "debug", + skip_all, + fields(sui_digest = tracing::field::Empty), + )] pub async fn execute( &mut self, mut builder: TransactionBuilder, @@ -282,6 +287,11 @@ impl SuiTxExecutor { .await? .into_inner(); + tracing::Span::current().record( + "sui_digest", + tracing::field::display(response.transaction().digest()), + ); + Ok(response) } @@ -292,6 +302,11 @@ impl SuiTxExecutor { /// Execute a deposit confirmation transaction. /// /// Passes a `Certificate` (BCS-encoded struct) to `deposit::confirm_deposit`. + #[tracing::instrument( + level = "info", + skip_all, + fields(deposit_id = %deposit_request.id), + )] pub async fn execute_confirm_deposit( &mut self, deposit_request: &DepositRequest, @@ -334,6 +349,11 @@ impl SuiTxExecutor { /// /// This builds and executes a PTB that calls `deposit::delete_expired_deposit` /// for each expired request in the batch. + #[tracing::instrument( + level = "info", + skip_all, + fields(expired_count = expired_requests.len()), + )] pub async fn execute_delete_expired_deposit_requests( &mut self, expired_requests: &[DepositRequest], @@ -384,6 +404,11 @@ impl SuiTxExecutor { /// /// Note: The `txid` parameter should be the Bitcoin transaction ID converted to a Sui Address /// (i.e., the 32-byte txid interpreted as a Sui address). + #[tracing::instrument( + level = "info", + skip_all, + fields(bitcoin_txid = %txid, vout, amount = amount_sats), + )] pub async fn execute_create_deposit_request( &mut self, txid: Address, @@ -471,6 +496,11 @@ impl SuiTxExecutor { /// 2. Calling deposit(hashi, utxo, clock) which creates the DepositRequest on-chain /// /// Returns the deposit request IDs on success. + #[tracing::instrument( + level = "info", + skip_all, + fields(bitcoin_txid = %txid, utxo_count = utxos.len()), + )] pub async fn execute_create_deposit_requests_batch( &mut self, txid: Address, @@ -567,6 +597,11 @@ impl SuiTxExecutor { /// /// Callers must ensure the batch size stays within the PTB command limit /// (roughly 300 deposits per PTB due to the 1024-command cap). + #[tracing::instrument( + level = "info", + skip_all, + fields(deposit_count = deposits.len()), + )] pub async fn execute_create_deposit_requests_multi( &mut self, deposits: &[(Address, u32, u64)], @@ -656,6 +691,11 @@ impl SuiTxExecutor { /// 2. Calling `withdraw::request_withdrawal` /// /// Returns the withdrawal request ID on success. + #[tracing::instrument( + level = "info", + skip_all, + fields(amount = withdrawal_amount_sats, request_id = tracing::field::Empty), + )] pub async fn execute_create_withdrawal_request( &mut self, withdrawal_amount_sats: u64, @@ -710,6 +750,10 @@ impl SuiTxExecutor { for event in response.transaction().events().events() { if event.contents().name().contains("WithdrawalRequestedEvent") { let event_data = WithdrawalRequestedEvent::from_bcs(event.contents().value())?; + tracing::Span::current().record( + "request_id", + tracing::field::display(&event_data.request_id), + ); return Ok(event_data.request_id); } } @@ -717,6 +761,7 @@ impl SuiTxExecutor { anyhow::bail!("WithdrawalRequestedEvent not found in transaction events") } + #[tracing::instrument(level = "info", skip_all)] pub async fn execute_start_reconfig(&mut self) -> anyhow::Result<()> { let mut builder = TransactionBuilder::new(); let hashi_arg = builder.object( @@ -747,6 +792,7 @@ impl SuiTxExecutor { Ok(()) } + #[tracing::instrument(level = "info", skip_all)] pub async fn execute_end_reconfig( &mut self, mpc_public_key: &[u8], @@ -779,6 +825,11 @@ impl SuiTxExecutor { } /// Reassign presig indices for a withdrawal transaction from a previous epoch. + #[tracing::instrument( + level = "info", + skip_all, + fields(withdrawal_txn_id = %withdrawal_id), + )] pub async fn execute_allocate_presigs_for_withdrawal_txn( &mut self, withdrawal_id: Address, @@ -813,6 +864,7 @@ impl SuiTxExecutor { /// Delegates to [`build_register_or_update_validator_tx`] to determine which /// move calls are needed, then signs and executes the resulting transaction. /// Returns `Ok(false)` if nothing needed to be updated. + #[tracing::instrument(level = "info", skip_all)] pub async fn execute_register_or_update_validator( &mut self, config: &Config, @@ -858,6 +910,11 @@ impl SuiTxExecutor { /// This submits a DKG, rotation, or nonce generation certificate to the on-chain /// certificate store. The certificate contains the dealer's message hash and /// committee signature. + #[tracing::instrument( + level = "info", + skip_all, + fields(cert_kind = tracing::field::Empty), + )] pub async fn execute_submit_certificate(&mut self, cert: &CertificateV1) -> anyhow::Result<()> { let (inner_cert, function_name, batch_index) = match cert { CertificateV1::Dkg(c) => (c, "submit_dkg_cert", None), @@ -866,6 +923,7 @@ impl SuiTxExecutor { (cert, "submit_nonce_cert", Some(*batch_index)) } }; + tracing::Span::current().record("cert_kind", function_name); let message = inner_cert.message(); let dealer = message.dealer_address; @@ -911,6 +969,11 @@ impl SuiTxExecutor { } /// Execute `withdraw::approve_request` to approve withdrawal requests on-chain. + #[tracing::instrument( + level = "info", + skip_all, + fields(batch_size = approvals.len()), + )] pub async fn execute_approve_withdrawal_requests( &mut self, approvals: &[(Address, &CommitteeSignature)], @@ -950,6 +1013,14 @@ impl SuiTxExecutor { /// Execute `withdraw::commit_withdrawal_tx` to commit to a withdrawal on-chain. /// - `r: &Random` + #[tracing::instrument( + level = "info", + skip_all, + fields( + bitcoin_txid = %approval.txid, + request_count = approval.request_ids.len(), + ), + )] pub async fn execute_commit_withdrawal_tx( &mut self, approval: &WithdrawalTxCommitment, @@ -1062,6 +1133,15 @@ impl SuiTxExecutor { /// handle this, the signatures are split into chunks that each fit within /// the pure-arg budget and stitched back together via /// `0x1::vector::append` calls in the PTB. + #[tracing::instrument( + level = "info", + skip_all, + fields( + withdrawal_txn_id = %withdrawal_id, + request_count = request_ids.len(), + input_count = signatures.len(), + ), + )] pub async fn execute_sign_withdrawal( &mut self, withdrawal_id: &Address, @@ -1111,6 +1191,11 @@ impl SuiTxExecutor { /// /// The Move function returns a `Balance` which is sent back to the /// sender's address balance. + #[tracing::instrument( + level = "info", + skip_all, + fields(request_id = %withdrawal_id), + )] pub async fn execute_cancel_withdrawal( &mut self, withdrawal_id: &Address, @@ -1172,6 +1257,11 @@ impl SuiTxExecutor { /// The Move function expects: /// - `hashi: &mut Hashi` /// - `withdrawal_id: address` + #[tracing::instrument( + level = "info", + skip_all, + fields(withdrawal_txn_id = %withdrawal_id), + )] pub async fn execute_confirm_withdrawal( &mut self, withdrawal_id: &Address, diff --git a/crates/hashi/src/withdrawals.rs b/crates/hashi/src/withdrawals.rs index 65eca3f31..3ef640a5c 100644 --- a/crates/hashi/src/withdrawals.rs +++ b/crates/hashi/src/withdrawals.rs @@ -104,6 +104,7 @@ pub struct WithdrawalConfirmation { impl Hashi { // --- Step 1: Request approval (lightweight) --- + #[tracing::instrument(level = "info", skip_all, fields(request_id = %approval.request_id))] pub async fn validate_and_sign_withdrawal_request_approval( &self, approval: &WithdrawalRequestApproval, @@ -132,6 +133,7 @@ impl Hashi { // --- Step 2: Construction approval (with UTXO selection) --- + #[tracing::instrument(level = "info", skip_all, fields(bitcoin_txid = %approval.txid))] pub async fn validate_and_sign_withdrawal_tx_commitment( &self, approval: &WithdrawalTxCommitment, @@ -140,6 +142,7 @@ impl Hashi { self.sign_withdrawal_tx_commitment(approval) } + #[tracing::instrument(level = "debug", skip_all, fields(bitcoin_txid = %approval.txid))] pub async fn validate_withdrawal_tx_commitment( &self, approval: &WithdrawalTxCommitment, @@ -396,6 +399,7 @@ impl Hashi { // --- Step 3: Sign withdrawal (store witness signatures on-chain) --- + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_id = %message.withdrawal_id))] pub fn validate_and_sign_withdrawal_tx_signing( &self, message: &WithdrawalTxSigning, @@ -496,6 +500,7 @@ impl Hashi { // --- MPC BTC tx signing --- + #[tracing::instrument(level = "info", skip_all, fields(withdrawal_txn_id = %withdrawal_txn_id))] pub async fn validate_and_sign_withdrawal_tx( &self, withdrawal_txn_id: &Address, @@ -532,6 +537,11 @@ impl Hashi { } /// Produce MPC Schnorr signatures for an unsigned withdrawal transaction. + #[tracing::instrument( + level = "debug", + skip_all, + fields(withdrawal_txn_id = %txn.id, input_count = txn.inputs.len()), + )] async fn mpc_sign_withdrawal_tx( &self, txn: &crate::onchain::types::WithdrawalTransaction, @@ -706,6 +716,7 @@ impl Hashi { /// UTXOs using the batching-aware coin selection algorithm, build the /// unsigned BTC tx, and return a `WithdrawalTxCommitment` covering the /// selected requests. + #[tracing::instrument(level = "debug", skip_all, fields(request_count = requests.len()))] pub async fn build_withdrawal_tx_commitment( &self, requests: &[WithdrawalRequest], @@ -835,6 +846,7 @@ impl Hashi { /// Run AML/Sanctions checks for a withdrawal request. /// If no screener client is configured, checks are skipped. + #[tracing::instrument(level = "debug", skip_all, fields(request_id = %request.id))] pub(crate) async fn screen_withdrawal( &self, request: &WithdrawalRequest, diff --git a/docker/hashi-screener/Containerfile b/docker/hashi-screener/Containerfile index a99121228..b96bd6b12 100644 --- a/docker/hashi-screener/Containerfile +++ b/docker/hashi-screener/Containerfile @@ -16,6 +16,7 @@ COPY --from=busybox . / COPY Cargo.toml Cargo.lock /src/ COPY crates/hashi-screener/Cargo.toml /src/crates/hashi-screener/Cargo.toml COPY crates/hashi-types/Cargo.toml /src/crates/hashi-types/Cargo.toml +COPY crates/hashi-telemetry/Cargo.toml /src/crates/hashi-telemetry/Cargo.toml WORKDIR /src @@ -24,7 +25,9 @@ RUN mkdir -p crates/hashi-screener/src \ && echo 'fn main(){}' > crates/hashi-screener/src/main.rs \ && touch crates/hashi-screener/src/lib.rs \ && mkdir -p crates/hashi-types/src \ - && touch crates/hashi-types/src/lib.rs + && touch crates/hashi-types/src/lib.rs \ + && mkdir -p crates/hashi-telemetry/src \ + && touch crates/hashi-telemetry/src/lib.rs ENV TARGET=x86_64-unknown-linux-musl ENV OPENSSL_STATIC=true @@ -44,6 +47,7 @@ ENV GIT_REVISION=${GIT_REVISION} COPY crates/hashi-screener /src/crates/hashi-screener COPY crates/hashi-types /src/crates/hashi-types +COPY crates/hashi-telemetry /src/crates/hashi-telemetry # Touch source files to invalidate cargo's fingerprint cache for local crates RUN find crates/ -name "*.rs" -exec touch {} + diff --git a/docker/hashi/Containerfile b/docker/hashi/Containerfile index 9a8813fbb..dbf1a60df 100644 --- a/docker/hashi/Containerfile +++ b/docker/hashi/Containerfile @@ -14,6 +14,7 @@ COPY --from=busybox . / COPY Cargo.toml Cargo.lock /src/ COPY crates/hashi/Cargo.toml /src/crates/hashi/Cargo.toml COPY crates/hashi-types/Cargo.toml /src/crates/hashi-types/Cargo.toml +COPY crates/hashi-telemetry/Cargo.toml /src/crates/hashi-telemetry/Cargo.toml WORKDIR /src @@ -22,7 +23,9 @@ RUN mkdir -p crates/hashi/src \ && echo 'fn main(){}' > crates/hashi/src/main.rs \ && touch crates/hashi/src/lib.rs \ && mkdir -p crates/hashi-types/src \ - && touch crates/hashi-types/src/lib.rs + && touch crates/hashi-types/src/lib.rs \ + && mkdir -p crates/hashi-telemetry/src \ + && touch crates/hashi-telemetry/src/lib.rs ENV TARGET=x86_64-unknown-linux-musl ENV OPENSSL_STATIC=true @@ -43,6 +46,7 @@ ENV GIT_REVISION=${GIT_REVISION} COPY crates/hashi /src/crates/hashi COPY crates/hashi-types /src/crates/hashi-types +COPY crates/hashi-telemetry /src/crates/hashi-telemetry # Touch source files to invalidate cargo's fingerprint cache for local crates RUN find crates/ -name "*.rs" -exec touch {} + From d3e36fa3724954a12e8ed9714ca68b5a424e633e Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Tue, 14 Apr 2026 17:47:47 -0700 Subject: [PATCH 2/6] [telemetry] Trim verbose docs and inline comments from hashi-telemetry MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The big module-level bullet list, per-field doc comments, per-method doc comments, and the inline NOTE block in init() were mostly describing what the code already says. Keep one short module-level summary and one line on with_env's RUST_LOG_JSON parsing (the only non-obvious bit — silent fall-through on unknown values). --- crates/hashi-telemetry/src/lib.rs | 75 ++----------------------------- 1 file changed, 3 insertions(+), 72 deletions(-) diff --git a/crates/hashi-telemetry/src/lib.rs b/crates/hashi-telemetry/src/lib.rs index 71ee52d47..0405a1de9 100644 --- a/crates/hashi-telemetry/src/lib.rs +++ b/crates/hashi-telemetry/src/lib.rs @@ -1,21 +1,7 @@ // Copyright (c) Mysten Labs, Inc. // SPDX-License-Identifier: Apache-2.0 -//! Shared telemetry configuration for all hashi binaries. -//! -//! Provides a [`TelemetryConfig`] builder that sets up a `tracing` subscriber with: -//! - **JSON output** for production (Kubernetes / Grafana / Loki) -//! - **Human-readable TTY output** for local development -//! - Automatic format detection based on [`std::io::IsTerminal`] for stderr: -//! stderr is a terminal → human, stderr is a pipe/redirect → JSON. -//! - `RUST_LOG` environment variable support via [`tracing_subscriber::EnvFilter`] -//! - `RUST_LOG_JSON=1`/`0` hard override. CI workflows that want human-readable -//! logs in pipe'd GitHub Actions output should set `RUST_LOG_JSON=0` in the -//! workflow env block. -//! -//! Service-level identification (filtering Loki by `hashi` vs `hashi-screener` -//! etc.) is delegated to Kubernetes pod labels injected by Promtail/Alloy at -//! ingest time, not written into the log body. Use `{app="hashi"}` in LogQL. +//! Shared `tracing` subscriber initialization for all hashi binaries. use std::io::IsTerminal; use std::io::stderr; @@ -26,35 +12,10 @@ use tracing_subscriber::Layer; use tracing_subscriber::layer::SubscriberExt; use tracing_subscriber::util::SubscriberInitExt; -/// Configuration for the tracing subscriber. -/// -/// # Examples -/// -/// ```no_run -/// use hashi_telemetry::TelemetryConfig; -/// -/// // Production server: auto-detect JSON vs TTY, INFO default -/// let _guard = TelemetryConfig::new() -/// .with_file_line(true) -/// .with_env() -/// .init(); -/// -/// // CLI tool: WARN default, no target, verbose override -/// let _guard = TelemetryConfig::new() -/// .with_default_level(tracing::level_filters::LevelFilter::WARN) -/// .with_target(false) -/// .with_env() -/// .init(); -/// ``` pub struct TelemetryConfig { - /// Base log level when `RUST_LOG` is not set. Default: `INFO`. default_level: LevelFilter, - /// Force JSON (`Some(true)`) or TTY (`Some(false)`) output. - /// `None` means auto-detect — see [`TelemetryConfig::init`]. json: Option, - /// Show `file:line` in log output. Default: `false`. file_line: bool, - /// Show module target path in log output. Default: `true`. target: bool, } @@ -65,7 +26,6 @@ impl Default for TelemetryConfig { } impl TelemetryConfig { - /// Create a new config with sensible defaults (INFO level, auto-detect format). pub fn new() -> Self { Self { default_level: LevelFilter::INFO, @@ -75,41 +35,30 @@ impl TelemetryConfig { } } - /// Set the default log level (used when `RUST_LOG` is not set). pub fn with_default_level(mut self, level: LevelFilter) -> Self { self.default_level = level; self } - /// Force JSON (`true`) or TTY (`false`) output, overriding auto-detection. pub fn with_json(mut self, json: bool) -> Self { self.json = Some(json); self } - /// Show `file:line` in log output. pub fn with_file_line(mut self, enabled: bool) -> Self { self.file_line = enabled; self } - /// Show module target path in log output. pub fn with_target(mut self, enabled: bool) -> Self { self.target = enabled; self } - /// Read configuration overrides from environment variables. - /// - /// `RUST_LOG_JSON`: - /// - `0`, `false`, `no` (case-insensitive) → force JSON off, use the - /// human-readable format even inside a pipe or container. - /// - any other non-empty value → force JSON on, overriding auto-detection. - /// - unset → leave the auto-detected choice in place. + /// `RUST_LOG_JSON=0`/`false`/`no` forces TTY; any other value forces JSON. pub fn with_env(mut self) -> Self { if let Ok(value) = std::env::var("RUST_LOG_JSON") { - let normalized = value.trim().to_ascii_lowercase(); - self.json = match normalized.as_str() { + self.json = match value.trim().to_ascii_lowercase().as_str() { "0" | "false" | "no" => Some(false), _ => Some(true), }; @@ -117,13 +66,6 @@ impl TelemetryConfig { self } - /// Build and install the tracing subscriber. - /// - /// Auto-detects the format when neither [`TelemetryConfig::with_json`] nor - /// `RUST_LOG_JSON` is set: stderr is a terminal → human format; stderr is - /// a pipe / redirect → JSON. - /// - /// Returns a [`TelemetryGuard`] that must be held alive for the duration of the program. pub fn init(self) -> TelemetryGuard { let use_json = match self.json { Some(true) => true, @@ -136,13 +78,6 @@ impl TelemetryConfig { .from_env_lossy(); if use_json { - // NOTE: JSON output always includes file/line regardless of the - // `with_file_line` setting. In production (Kubernetes → Loki) we - // always want the exact source location on every event for - // debuggability, and the cost of the extra fields on structured - // output is negligible. The `with_file_line` builder setting only - // affects the TTY branch below, where it is off by default to - // keep local dev output uncluttered. let fmt_layer = tracing_subscriber::fmt::layer() .with_file(true) .with_line_number(true) @@ -166,10 +101,6 @@ impl TelemetryConfig { } } -/// Guard that must be held alive for the duration of the program. -/// -/// Future additions (non-blocking writer flush, OpenTelemetry shutdown) -/// will be handled in its `Drop` implementation. #[must_use = "dropping the guard immediately will lose buffered log output"] pub struct TelemetryGuard { _private: (), From 5d6963fb827c839e9dea2d1cd911a4eb00dea06a Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Tue, 14 Apr 2026 17:54:10 -0700 Subject: [PATCH 3/6] [telemetry] Fold hashi-telemetry into a module under hashi-types MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Per code-review feedback: hashi-telemetry was small enough that the extra crate wasn't pulling its weight. Move the whole thing to hashi_types::telemetry and delete the standalone crate. - crates/hashi-telemetry/ → crates/hashi-types/src/telemetry.rs - hashi-types now depends on tracing-subscriber (already transitively present in every workspace consumer except internal-tools, which already has it too) - All 5 binaries drop `hashi-telemetry = ...` and swap `hashi_telemetry::TelemetryConfig` for `hashi_types::telemetry::TelemetryConfig` - Docker Containerfiles for hashi and hashi-screener drop the extra COPY/stub-source steps for the removed crate --- .github/workflows/ci.yml | 5 +++-- Cargo.lock | 14 +------------- crates/e2e-tests/Cargo.toml | 1 - crates/e2e-tests/src/main.rs | 2 +- crates/hashi-guardian/Cargo.toml | 1 - crates/hashi-guardian/src/main.rs | 2 +- crates/hashi-monitor/Cargo.toml | 1 - crates/hashi-monitor/src/main.rs | 2 +- crates/hashi-screener/Cargo.toml | 1 - crates/hashi-screener/src/main.rs | 2 +- crates/hashi-telemetry/Cargo.toml | 9 --------- crates/hashi-types/Cargo.toml | 1 + crates/hashi-types/src/lib.rs | 1 + .../src/lib.rs => hashi-types/src/telemetry.rs} | 0 crates/hashi/Cargo.toml | 1 - crates/hashi/src/cli/mod.rs | 2 +- crates/hashi/src/main.rs | 2 +- docker/hashi-screener/Containerfile | 6 +----- docker/hashi/Containerfile | 6 +----- 19 files changed, 14 insertions(+), 45 deletions(-) delete mode 100644 crates/hashi-telemetry/Cargo.toml rename crates/{hashi-telemetry/src/lib.rs => hashi-types/src/telemetry.rs} (100%) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index bbc2de48d..c84eca166 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -11,8 +11,9 @@ permissions: env: RUSTFLAGS: -Dwarnings # Force human-readable log output even though stderr is a pipe in GitHub - # Actions runners. Any hashi binary invoked from this workflow uses - # hashi-telemetry, which would otherwise auto-detect JSON for non-TTY stderr. + # Actions runners. Any hashi binary invoked from this workflow uses the + # telemetry module in hashi-types, which would otherwise auto-detect JSON + # for non-TTY stderr. RUST_LOG_JSON: "0" jobs: diff --git a/Cargo.lock b/Cargo.lock index 74b53f770..1c336c13e 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2088,7 +2088,6 @@ dependencies = [ "futures", "hashi", "hashi-screener", - "hashi-telemetry", "hashi-types", "nix", "prometheus", @@ -2829,7 +2828,6 @@ dependencies = [ "fastcrypto-tbls", "fjall", "futures", - "hashi-telemetry", "hashi-types", "hex", "jiff", @@ -2884,7 +2882,6 @@ dependencies = [ "aws-sdk-s3", "aws-smithy-mocks", "bitcoin", - "hashi-telemetry", "hashi-types", "hpke", "k256", @@ -2908,7 +2905,6 @@ dependencies = [ "corepc-client", "e2e-tests", "hashi-guardian", - "hashi-telemetry", "hashi-types", "hex", "hpke", @@ -2932,7 +2928,6 @@ dependencies = [ "axum", "backon", "bitcoin", - "hashi-telemetry", "hashi-types", "lru", "prometheus", @@ -2951,14 +2946,6 @@ dependencies = [ "tracing-subscriber", ] -[[package]] -name = "hashi-telemetry" -version = "0.1.0" -dependencies = [ - "tracing", - "tracing-subscriber", -] - [[package]] name = "hashi-types" version = "0.0.0" @@ -2994,6 +2981,7 @@ dependencies = [ "tonic", "tonic-prost", "tracing", + "tracing-subscriber", ] [[package]] diff --git a/crates/e2e-tests/Cargo.toml b/crates/e2e-tests/Cargo.toml index 8acaf5466..8dd15cd7d 100644 --- a/crates/e2e-tests/Cargo.toml +++ b/crates/e2e-tests/Cargo.toml @@ -33,7 +33,6 @@ colored.workspace = true rand.workspace = true nix = { version = "0.26.4", features = ["signal"] } tracing-subscriber.workspace = true -hashi-telemetry = { path = "../hashi-telemetry" } [[bin]] name = "hashi-localnet" diff --git a/crates/e2e-tests/src/main.rs b/crates/e2e-tests/src/main.rs index ec44e3c13..39f7a0910 100644 --- a/crates/e2e-tests/src/main.rs +++ b/crates/e2e-tests/src/main.rs @@ -279,7 +279,7 @@ async fn cmd_start( tracing::level_filters::LevelFilter::OFF }; - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_default_level(default_level) .with_target(false) .with_env() diff --git a/crates/hashi-guardian/Cargo.toml b/crates/hashi-guardian/Cargo.toml index 59ad86667..a3a119969 100644 --- a/crates/hashi-guardian/Cargo.toml +++ b/crates/hashi-guardian/Cargo.toml @@ -11,7 +11,6 @@ serde.workspace = true serde_json.workspace = true tracing.workspace = true tracing-subscriber.workspace = true -hashi-telemetry = { path = "../hashi-telemetry" } tonic.workspace = true hashi-types = { path = "../hashi-types" } diff --git a/crates/hashi-guardian/src/main.rs b/crates/hashi-guardian/src/main.rs index a8292e96b..3d638715e 100644 --- a/crates/hashi-guardian/src/main.rs +++ b/crates/hashi-guardian/src/main.rs @@ -102,7 +102,7 @@ pub struct EphemeralKeyPairs { /// SETUP_MODE=false: all endpoints except setup_new_key are enabled. #[tokio::main] async fn main() -> Result<()> { - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); diff --git a/crates/hashi-monitor/Cargo.toml b/crates/hashi-monitor/Cargo.toml index 2c2edec8f..95f7c4ef5 100644 --- a/crates/hashi-monitor/Cargo.toml +++ b/crates/hashi-monitor/Cargo.toml @@ -22,7 +22,6 @@ tokio.workspace = true tonic.workspace = true tracing.workspace = true tracing-subscriber.workspace = true -hashi-telemetry = { path = "../hashi-telemetry" } [dev-dependencies] e2e-tests = { path = "../e2e-tests" } diff --git a/crates/hashi-monitor/src/main.rs b/crates/hashi-monitor/src/main.rs index 4bbe6852f..aaff3fb62 100644 --- a/crates/hashi-monitor/src/main.rs +++ b/crates/hashi-monitor/src/main.rs @@ -51,7 +51,7 @@ enum Command { #[tokio::main] async fn main() -> anyhow::Result<()> { - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_target(false) .with_env() .init(); diff --git a/crates/hashi-screener/Cargo.toml b/crates/hashi-screener/Cargo.toml index 720a63059..230dffb50 100644 --- a/crates/hashi-screener/Cargo.toml +++ b/crates/hashi-screener/Cargo.toml @@ -11,7 +11,6 @@ thiserror.workspace = true tokio.workspace = true tracing.workspace = true tracing-subscriber.workspace = true -hashi-telemetry = { path = "../hashi-telemetry" } prometheus.workspace = true axum.workspace = true sui-http.workspace = true diff --git a/crates/hashi-screener/src/main.rs b/crates/hashi-screener/src/main.rs index 2c8ea3456..68333dc16 100644 --- a/crates/hashi-screener/src/main.rs +++ b/crates/hashi-screener/src/main.rs @@ -252,7 +252,7 @@ async fn metrics_handler( #[tokio::main] async fn main() -> Result<()> { - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); diff --git a/crates/hashi-telemetry/Cargo.toml b/crates/hashi-telemetry/Cargo.toml deleted file mode 100644 index 1dad54840..000000000 --- a/crates/hashi-telemetry/Cargo.toml +++ /dev/null @@ -1,9 +0,0 @@ -[package] -name = "hashi-telemetry" -version = "0.1.0" -edition = "2024" -publish = false - -[dependencies] -tracing.workspace = true -tracing-subscriber.workspace = true diff --git a/crates/hashi-types/Cargo.toml b/crates/hashi-types/Cargo.toml index c3a0657e8..9ffafd88c 100644 --- a/crates/hashi-types/Cargo.toml +++ b/crates/hashi-types/Cargo.toml @@ -37,6 +37,7 @@ ed25519-consensus = "2.1" miniscript = "13.0.0" serde_json.workspace = true tracing.workspace = true +tracing-subscriber.workspace = true time = "0.3" hex.workspace = true diff --git a/crates/hashi-types/src/lib.rs b/crates/hashi-types/src/lib.rs index d34fbab8b..01294a36a 100644 --- a/crates/hashi-types/src/lib.rs +++ b/crates/hashi-types/src/lib.rs @@ -6,4 +6,5 @@ pub mod committee; pub mod guardian; pub mod move_types; pub mod proto; +pub mod telemetry; pub mod utils; diff --git a/crates/hashi-telemetry/src/lib.rs b/crates/hashi-types/src/telemetry.rs similarity index 100% rename from crates/hashi-telemetry/src/lib.rs rename to crates/hashi-types/src/telemetry.rs diff --git a/crates/hashi/Cargo.toml b/crates/hashi/Cargo.toml index edc2c1b97..5a8cb3e61 100644 --- a/crates/hashi/Cargo.toml +++ b/crates/hashi/Cargo.toml @@ -35,7 +35,6 @@ tower.workspace = true tokio.workspace = true prometheus.workspace = true tracing.workspace = true -hashi-telemetry = { path = "../hashi-telemetry" } bin-version.workspace = true prometheus-closure-metric.workspace = true diff --git a/crates/hashi/src/cli/mod.rs b/crates/hashi/src/cli/mod.rs index ceb434837..94b456084 100644 --- a/crates/hashi/src/cli/mod.rs +++ b/crates/hashi/src/cli/mod.rs @@ -675,7 +675,7 @@ fn init_tracing(verbose: bool) { }; // Guard is intentionally leaked — the CLI runs to completion in main(). - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_default_level(level) .with_target(false) .with_env() diff --git a/crates/hashi/src/main.rs b/crates/hashi/src/main.rs index d7ba555f1..262632796 100644 --- a/crates/hashi/src/main.rs +++ b/crates/hashi/src/main.rs @@ -158,7 +158,7 @@ async fn main() -> anyhow::Result<()> { } async fn run_server(config_path: Option) -> anyhow::Result<()> { - let _guard = hashi_telemetry::TelemetryConfig::new() + let _guard = hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); diff --git a/docker/hashi-screener/Containerfile b/docker/hashi-screener/Containerfile index b96bd6b12..a99121228 100644 --- a/docker/hashi-screener/Containerfile +++ b/docker/hashi-screener/Containerfile @@ -16,7 +16,6 @@ COPY --from=busybox . / COPY Cargo.toml Cargo.lock /src/ COPY crates/hashi-screener/Cargo.toml /src/crates/hashi-screener/Cargo.toml COPY crates/hashi-types/Cargo.toml /src/crates/hashi-types/Cargo.toml -COPY crates/hashi-telemetry/Cargo.toml /src/crates/hashi-telemetry/Cargo.toml WORKDIR /src @@ -25,9 +24,7 @@ RUN mkdir -p crates/hashi-screener/src \ && echo 'fn main(){}' > crates/hashi-screener/src/main.rs \ && touch crates/hashi-screener/src/lib.rs \ && mkdir -p crates/hashi-types/src \ - && touch crates/hashi-types/src/lib.rs \ - && mkdir -p crates/hashi-telemetry/src \ - && touch crates/hashi-telemetry/src/lib.rs + && touch crates/hashi-types/src/lib.rs ENV TARGET=x86_64-unknown-linux-musl ENV OPENSSL_STATIC=true @@ -47,7 +44,6 @@ ENV GIT_REVISION=${GIT_REVISION} COPY crates/hashi-screener /src/crates/hashi-screener COPY crates/hashi-types /src/crates/hashi-types -COPY crates/hashi-telemetry /src/crates/hashi-telemetry # Touch source files to invalidate cargo's fingerprint cache for local crates RUN find crates/ -name "*.rs" -exec touch {} + diff --git a/docker/hashi/Containerfile b/docker/hashi/Containerfile index dbf1a60df..9a8813fbb 100644 --- a/docker/hashi/Containerfile +++ b/docker/hashi/Containerfile @@ -14,7 +14,6 @@ COPY --from=busybox . / COPY Cargo.toml Cargo.lock /src/ COPY crates/hashi/Cargo.toml /src/crates/hashi/Cargo.toml COPY crates/hashi-types/Cargo.toml /src/crates/hashi-types/Cargo.toml -COPY crates/hashi-telemetry/Cargo.toml /src/crates/hashi-telemetry/Cargo.toml WORKDIR /src @@ -23,9 +22,7 @@ RUN mkdir -p crates/hashi/src \ && echo 'fn main(){}' > crates/hashi/src/main.rs \ && touch crates/hashi/src/lib.rs \ && mkdir -p crates/hashi-types/src \ - && touch crates/hashi-types/src/lib.rs \ - && mkdir -p crates/hashi-telemetry/src \ - && touch crates/hashi-telemetry/src/lib.rs + && touch crates/hashi-types/src/lib.rs ENV TARGET=x86_64-unknown-linux-musl ENV OPENSSL_STATIC=true @@ -46,7 +43,6 @@ ENV GIT_REVISION=${GIT_REVISION} COPY crates/hashi /src/crates/hashi COPY crates/hashi-types /src/crates/hashi-types -COPY crates/hashi-telemetry /src/crates/hashi-telemetry # Touch source files to invalidate cargo's fingerprint cache for local crates RUN find crates/ -name "*.rs" -exec touch {} + From e4a9c97c9bbf8ee1c066f8b0d83decb9a8b95b1b Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Tue, 14 Apr 2026 17:56:54 -0700 Subject: [PATCH 4/6] [ci] Drop verbose comment on RUST_LOG_JSON env var --- .github/workflows/ci.yml | 4 ---- 1 file changed, 4 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index c84eca166..22df3520f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -10,10 +10,6 @@ permissions: env: RUSTFLAGS: -Dwarnings - # Force human-readable log output even though stderr is a pipe in GitHub - # Actions runners. Any hashi binary invoked from this workflow uses the - # telemetry module in hashi-types, which would otherwise auto-detect JSON - # for non-TTY stderr. RUST_LOG_JSON: "0" jobs: From 01b316ba23adb5017a9490802b3513dc3264a34f Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Wed, 15 Apr 2026 13:13:57 -0700 Subject: [PATCH 5/6] [telemetry] Drop no-op TelemetryGuard and lift hashi-localnet init to main The guard was a ZST marker with no Drop impl and no buffered I/O to flush, so it could not do what its #[must_use] message claimed. The hashi-localnet init sat inside cmd_start, which meant FaucetSui and Deposit silently dropped their spans; lift verbose to a global clap flag and initialize tracing at the top of main, matching every other binary. --- crates/e2e-tests/src/main.rs | 44 +++++++++++------------------ crates/hashi-guardian/src/main.rs | 2 +- crates/hashi-monitor/src/main.rs | 2 +- crates/hashi-screener/src/main.rs | 2 +- crates/hashi-types/src/telemetry.rs | 9 +----- crates/hashi/src/cli/mod.rs | 3 +- crates/hashi/src/main.rs | 2 +- 7 files changed, 22 insertions(+), 42 deletions(-) diff --git a/crates/e2e-tests/src/main.rs b/crates/e2e-tests/src/main.rs index 39f7a0910..bcddcebd4 100644 --- a/crates/e2e-tests/src/main.rs +++ b/crates/e2e-tests/src/main.rs @@ -24,6 +24,10 @@ use std::path::Path; about = "Manage a local Hashi dev environment" )] struct Cli { + /// Enable verbose tracing output (INFO level). + #[clap(long, short, global = true)] + verbose: bool, + #[command(subcommand)] command: Commands, } @@ -73,10 +77,6 @@ enum Commands { #[clap(long, default_value = "18443")] btc_rpc_port: u16, - /// Enable verbose tracing output - #[clap(long, short)] - verbose: bool, - #[command(flatten)] opts: LocalnetOpts, }, @@ -215,23 +215,24 @@ fn print_warning(msg: &str) { async fn main() -> Result<()> { let cli = Cli::parse(); + let default_level = if cli.verbose { + tracing::level_filters::LevelFilter::INFO + } else { + tracing::level_filters::LevelFilter::OFF + }; + hashi_types::telemetry::TelemetryConfig::new() + .with_default_level(default_level) + .with_target(false) + .with_env() + .init(); + match cli.command { Commands::Start { num_validators, sui_rpc_port, btc_rpc_port, - verbose, opts, - } => { - cmd_start( - num_validators, - sui_rpc_port, - btc_rpc_port, - verbose, - &opts.data_dir, - ) - .await - } + } => cmd_start(num_validators, sui_rpc_port, btc_rpc_port, &opts.data_dir).await, Commands::Stop { opts } => cmd_stop(&opts.data_dir).await, Commands::Status { opts } => cmd_status(&opts.data_dir), Commands::Info { opts } => cmd_info(&opts.data_dir), @@ -259,7 +260,6 @@ async fn cmd_start( num_validators: usize, sui_rpc_port: u16, btc_rpc_port: u16, - verbose: bool, data_dir: &Path, ) -> Result<()> { // Check for existing running instance @@ -273,18 +273,6 @@ async fn cmd_start( print_warning("Found stale state file, cleaning up..."); } - let default_level = if verbose { - tracing::level_filters::LevelFilter::INFO - } else { - tracing::level_filters::LevelFilter::OFF - }; - - let _guard = hashi_types::telemetry::TelemetryConfig::new() - .with_default_level(default_level) - .with_target(false) - .with_env() - .init(); - use std::io::Write; print!( "{} Starting localnet with {} validators...", diff --git a/crates/hashi-guardian/src/main.rs b/crates/hashi-guardian/src/main.rs index 3d638715e..f82dd10b8 100644 --- a/crates/hashi-guardian/src/main.rs +++ b/crates/hashi-guardian/src/main.rs @@ -102,7 +102,7 @@ pub struct EphemeralKeyPairs { /// SETUP_MODE=false: all endpoints except setup_new_key are enabled. #[tokio::main] async fn main() -> Result<()> { - let _guard = hashi_types::telemetry::TelemetryConfig::new() + hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); diff --git a/crates/hashi-monitor/src/main.rs b/crates/hashi-monitor/src/main.rs index aaff3fb62..8db9f2b3a 100644 --- a/crates/hashi-monitor/src/main.rs +++ b/crates/hashi-monitor/src/main.rs @@ -51,7 +51,7 @@ enum Command { #[tokio::main] async fn main() -> anyhow::Result<()> { - let _guard = hashi_types::telemetry::TelemetryConfig::new() + hashi_types::telemetry::TelemetryConfig::new() .with_target(false) .with_env() .init(); diff --git a/crates/hashi-screener/src/main.rs b/crates/hashi-screener/src/main.rs index 68333dc16..8b894a75c 100644 --- a/crates/hashi-screener/src/main.rs +++ b/crates/hashi-screener/src/main.rs @@ -252,7 +252,7 @@ async fn metrics_handler( #[tokio::main] async fn main() -> Result<()> { - let _guard = hashi_types::telemetry::TelemetryConfig::new() + hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); diff --git a/crates/hashi-types/src/telemetry.rs b/crates/hashi-types/src/telemetry.rs index 0405a1de9..7cd0247d0 100644 --- a/crates/hashi-types/src/telemetry.rs +++ b/crates/hashi-types/src/telemetry.rs @@ -66,7 +66,7 @@ impl TelemetryConfig { self } - pub fn init(self) -> TelemetryGuard { + pub fn init(self) { let use_json = match self.json { Some(true) => true, Some(false) => false, @@ -96,12 +96,5 @@ impl TelemetryConfig { tracing_subscriber::registry().with(fmt_layer).init(); } - - TelemetryGuard { _private: () } } } - -#[must_use = "dropping the guard immediately will lose buffered log output"] -pub struct TelemetryGuard { - _private: (), -} diff --git a/crates/hashi/src/cli/mod.rs b/crates/hashi/src/cli/mod.rs index 94b456084..92259cf5b 100644 --- a/crates/hashi/src/cli/mod.rs +++ b/crates/hashi/src/cli/mod.rs @@ -674,8 +674,7 @@ fn init_tracing(verbose: bool) { tracing::level_filters::LevelFilter::WARN }; - // Guard is intentionally leaked — the CLI runs to completion in main(). - let _guard = hashi_types::telemetry::TelemetryConfig::new() + hashi_types::telemetry::TelemetryConfig::new() .with_default_level(level) .with_target(false) .with_env() diff --git a/crates/hashi/src/main.rs b/crates/hashi/src/main.rs index 262632796..941c1419f 100644 --- a/crates/hashi/src/main.rs +++ b/crates/hashi/src/main.rs @@ -158,7 +158,7 @@ async fn main() -> anyhow::Result<()> { } async fn run_server(config_path: Option) -> anyhow::Result<()> { - let _guard = hashi_types::telemetry::TelemetryConfig::new() + hashi_types::telemetry::TelemetryConfig::new() .with_file_line(true) .with_env() .init(); From cf300ec229dc5f405e50c1516e237a9e4a144d8b Mon Sep 17 00:00:00 2001 From: Siddharth Sharma Date: Wed, 15 Apr 2026 13:49:38 -0700 Subject: [PATCH 6/6] [telemetry] Write fmt layer output to stderr instead of stdout `tracing_subscriber::fmt::layer()` defaults its writer to stdout, so log output was leaking onto stdout even though every other signal in this module (TTY autodetect, ANSI colorization) is keyed off stderr. Explicitly set the writer on both the JSON and TTY branches. --- crates/hashi-types/src/telemetry.rs | 2 ++ 1 file changed, 2 insertions(+) diff --git a/crates/hashi-types/src/telemetry.rs b/crates/hashi-types/src/telemetry.rs index 7cd0247d0..10b672721 100644 --- a/crates/hashi-types/src/telemetry.rs +++ b/crates/hashi-types/src/telemetry.rs @@ -79,6 +79,7 @@ impl TelemetryConfig { if use_json { let fmt_layer = tracing_subscriber::fmt::layer() + .with_writer(stderr) .with_file(true) .with_line_number(true) .with_target(self.target) @@ -88,6 +89,7 @@ impl TelemetryConfig { tracing_subscriber::registry().with(fmt_layer).init(); } else { let fmt_layer = tracing_subscriber::fmt::layer() + .with_writer(stderr) .with_file(self.file_line) .with_line_number(self.file_line) .with_target(self.target)