From ad431e8b0944383dcaedbff61fa54d2cbe1d5616 Mon Sep 17 00:00:00 2001 From: Floriane TUERNAL SABOTINOV Date: Tue, 14 Oct 2025 09:33:54 +0200 Subject: [PATCH] cleanup and add guard to keep the tracer provider alive --- Cargo.lock | 1 + .../bin-common/src/opentelemetry/context.rs | 14 ++++++++++ common/bin-common/src/opentelemetry/mod.rs | 23 +++++++++++++--- common/nymsphinx/framing/src/processing.rs | 11 ++++---- nym-node/Cargo.toml | 1 + nym-node/src/cli/mod.rs | 22 +++++++++++----- sdk/rust/nym-sdk/examples/surb_reply.rs | 26 ++++++++++++------- 7 files changed, 73 insertions(+), 25 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 327fc2fe9a..e3d10b662b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6366,6 +6366,7 @@ dependencies = [ "nym-verloc", "nym-wireguard", "nym-wireguard-types", + "opentelemetry", "rand 0.8.5", "rand_chacha 0.3.1", "serde", diff --git a/common/bin-common/src/opentelemetry/context.rs b/common/bin-common/src/opentelemetry/context.rs index 88072a3282..023ffc2159 100644 --- a/common/bin-common/src/opentelemetry/context.rs +++ b/common/bin-common/src/opentelemetry/context.rs @@ -111,6 +111,20 @@ impl ManualContextPropagator { trace_id, } } + + pub fn new_from_tid(name: &str, trace_id: TraceId) -> Self { + let root_span_builder = new_span_context_with_id(trace_id.clone()); + let _guard = root_span_builder.clone().attach(); + + let root_span = tracing::info_span!("trace_root", name = %name, trace_id = %trace_id); + root_span.set_parent(root_span_builder); + + ManualContextPropagator { + root_span, + trace_id, + } + } + } pub fn new_span_context_with_id(trace_id: TraceId) -> Context { diff --git a/common/bin-common/src/opentelemetry/mod.rs b/common/bin-common/src/opentelemetry/mod.rs index 543ba5ab59..e6dd8cde59 100644 --- a/common/bin-common/src/opentelemetry/mod.rs +++ b/common/bin-common/src/opentelemetry/mod.rs @@ -25,6 +25,19 @@ use opentelemetry_semantic_conventions::SCHEMA_URL; use tracing_opentelemetry::{MetricsLayer, OpenTelemetryLayer}; use tracing_subscriber::fmt::format::FmtSpan; +pub struct TracerProviderGuard(Option); + +impl Drop for TracerProviderGuard { + fn drop(&mut self) { + if let Some(tracer_provider) = self.0.take() { + // Ensure all spans are flushed before exit + if let Err(e) = tracer_provider.shutdown() { + eprintln!("Error shutting down tracer provider: {:?}", e); + } + } + } +} + pub(crate) fn granual_filtered_env() -> Result { fn directive_checked(directive: impl Into) -> Result { @@ -41,7 +54,7 @@ pub(crate) fn granual_filtered_env() -> Result Result<(), TracingError> { +pub fn setup_tracing_logger(service_name: String) -> Result { if tracing::dispatcher::has_been_set() { // It shouldn't be - this is really checking that it is torn down between async command executions return Err(error::TracingError::TracingLoggerAlreadyInitialised); @@ -74,7 +87,7 @@ pub fn setup_tracing_logger(service_name: String) -> Result<(), TracingError> { .with(console_layer) .with(fmt_layer) .with(granual_filtered_env()?) - .with(tracing_subscriber::filter::LevelFilter::from_level(Level::WARN)) + .with(tracing_subscriber::filter::LevelFilter::from_level(Level::INFO)) .with(MetricsLayer::new(meter_provider)) .with(OpenTelemetryLayer::new(tracer)) .try_init() @@ -83,14 +96,16 @@ pub fn setup_tracing_logger(service_name: String) -> Result<(), TracingError> { tracing_subscriber::registry() .with(fmt_layer) .with(granual_filtered_env()?) - .with(tracing_subscriber::filter::LevelFilter::from_level(Level::WARN)) + .with(tracing_subscriber::filter::LevelFilter::from_level(Level::INFO)) .with(MetricsLayer::new(meter_provider)) .with(OpenTelemetryLayer::new(tracer)) .try_init() .map_err(|e| TracingError::TracingTryInitError(e))?; }} + + let guard = TracerProviderGuard(Some(tracer_provider)); - Ok(()) + Ok(guard) } pub fn setup_no_otel_logger() -> Result<(), TracingError> { diff --git a/common/nymsphinx/framing/src/processing.rs b/common/nymsphinx/framing/src/processing.rs index 7884679c01..bca7eff0a6 100644 --- a/common/nymsphinx/framing/src/processing.rs +++ b/common/nymsphinx/framing/src/processing.rs @@ -3,6 +3,7 @@ use crate::packet::FramedNymPacket; use nym_bin_common::opentelemetry::compact_id_generator::decompress_trace_id; +use nym_bin_common::opentelemetry::context::ManualContextPropagator; use nym_sphinx_acknowledgements::surb_ack::{SurbAck, SurbAckRecoveryError}; use nym_sphinx_addressing::nodes::{NymNodeRoutingAddress, NymNodeRoutingAddressError}; use nym_sphinx_forwarding::packet::MixPacket; @@ -15,7 +16,7 @@ use nym_sphinx_types::{ }; use std::fmt::Display; use thiserror::Error; -use tracing::{debug, error, info, warn, trace, instrument}; +use tracing::{debug, error, info, instrument, trace, warn, warn_span}; #[derive(Debug)] pub enum MixProcessingResultData { @@ -270,11 +271,9 @@ fn wrap_processed_sphinx_packet( if !trace_bytes.iter().all(|b| *b == 0) { let full_trace_id_bytes = decompress_trace_id(&trace_bytes); let full_trace_id = opentelemetry::trace::TraceId::from_bytes(full_trace_id_bytes); - tracing::Span::current().record("trace_id", &full_trace_id.to_string().as_str()); - warn!("Processing final hop with trace_id: {full_trace_id:?}"); - } - else { - warn!("Received final hop with empty trace_id"); + let context_propagator = ManualContextPropagator::new_from_tid("final_hop", full_trace_id); + let span = warn_span!(parent: &context_propagator.root_span, "final_hop_processing", trace_id=%full_trace_id); + let _enter = span.enter(); } } diff --git a/nym-node/Cargo.toml b/nym-node/Cargo.toml index f5f86098b8..df72e19f7d 100644 --- a/nym-node/Cargo.toml +++ b/nym-node/Cargo.toml @@ -31,6 +31,7 @@ humantime-serde = { workspace = true } human-repr = { workspace = true } ipnetwork = { workspace = true } indicatif = { workspace = true } +opentelemetry = { workspace = true } # make it optional later rand = { workspace = true } serde = { workspace = true, features = ["derive"] } serde_json.workspace = true diff --git a/nym-node/src/cli/mod.rs b/nym-node/src/cli/mod.rs index 77cbd04c61..242c11686a 100644 --- a/nym-node/src/cli/mod.rs +++ b/nym-node/src/cli/mod.rs @@ -10,8 +10,12 @@ use crate::env::vars::{NYMNODE_CONFIG_ENV_FILE_ARG, NYMNODE_NO_BANNER_ARG}; use clap::{Args, Parser, Subcommand}; use nym_bin_common::{ bin_info, - opentelemetry::{setup_no_otel_logger, setup_tracing_logger, error::TracingError}, + opentelemetry::{ + setup_no_otel_logger, + setup_tracing_logger, + error::TracingError}, }; +use opentelemetry::{Context, global, trace::{TraceContextExt, Tracer}}; use std::future::Future; use std::sync::OnceLock; use tracing::instrument; @@ -85,27 +89,33 @@ impl Cli { }, // SigNoz/OTEL run in async context Commands::BondingInformation(args) => Self::execute_async(async move { - setup_tracing_logger("nym-node".to_string())?; + let _guard = setup_tracing_logger("nym-node".to_string()) + .map_err(TracingError::from)?; + bonding_information::execute(args).await?; Ok::<(), anyhow::Error>(()) })??, Commands::NodeDetails(args) => Self::execute_async(async move { - setup_tracing_logger("nym-node".to_string()).map_err(TracingError::from)?; + let _guard = setup_tracing_logger("nym-node".to_string()) + .map_err(TracingError::from)?; node_details::execute(args).await?; Ok::<(), anyhow::Error>(()) })??, Commands::Run(args) => Self::execute_async(async move { - setup_tracing_logger("nym-node".to_string()).map_err(TracingError::from)?; + let _guard = setup_tracing_logger("nym-node".to_string()) + .map_err(TracingError::from)?; run::execute(*args).await?; Ok::<(), anyhow::Error>(()) })??, Commands::Sign(args) => Self::execute_async(async move { - setup_tracing_logger("nym-node".to_string()).map_err(TracingError::from)?; + let _guard = setup_tracing_logger("nym-node".to_string()) + .map_err(TracingError::from)?; sign::execute(args).await?; Ok::<(), anyhow::Error>(()) })??, Commands::UnsafeResetSphinxKeys(args) => Self::execute_async(async move { - setup_tracing_logger("nym-node".to_string()).map_err(TracingError::from)?; + let _guard = setup_tracing_logger("nym-node".to_string()) + .map_err(TracingError::from)?; reset_sphinx_keys::execute(args).await?; Ok::<(), anyhow::Error>(()) })??, diff --git a/sdk/rust/nym-sdk/examples/surb_reply.rs b/sdk/rust/nym-sdk/examples/surb_reply.rs index 02c918a605..8a07ba1490 100644 --- a/sdk/rust/nym-sdk/examples/surb_reply.rs +++ b/sdk/rust/nym-sdk/examples/surb_reply.rs @@ -1,6 +1,7 @@ use nym_sdk::mixnet::{ AnonymousSenderTag, MixnetClientBuilder, MixnetMessageSender, ReconstructedMessage, }; +use nym_sdk::DebugConfig; use opentelemetry::trace::{TraceContextExt, Tracer}; use opentelemetry::{global, Context}; use tracing::warn; @@ -9,7 +10,7 @@ use tracing::instrument; #[tokio::main] #[instrument(name = "sdk-example-surb-reply", skip_all)] async fn main() { - nym_bin_common::opentelemetry::setup_tracing_logger("sdk-example-surb-reply".to_string()).unwrap(); + let _guard = nym_bin_common::opentelemetry::setup_tracing_logger("sdk-example-surb-reply".to_string()).unwrap(); let tracer = global::tracer("sdk-example-surb-reply"); let span = tracer.start("client-root-span"); @@ -19,17 +20,24 @@ async fn main() { let trace_id = cx.span().span_context().trace_id(); warn!("Main TRACE_ID: {:?}", trace_id); - // let span = info_span!( - // "surb_reply_example_session", - // trace_id = %trace_id.to_string() - // ); - // let _enter = span.enter(); - - // Create a mixnet client which connect to a specific node + let context = Context::current(); + println!("Current OTEL context: {:?}", context); + // Ignore performance requirements for the sake of the example + let mut debug_config = DebugConfig::default(); + debug_config.cover_traffic.disable_loop_cover_traffic_stream = true; + debug_config + .traffic + .disable_main_poisson_packet_distribution = true; + + debug_config.topology.minimum_mixnode_performance = 0; + debug_config.topology.minimum_gateway_performance = 0; + + // Create a mixnet client which connect to a specific node let client_builder = MixnetClientBuilder::new_ephemeral(); let mixnet_client = client_builder - .request_gateway("BAF2aYpzcK9KbSS3Y7EdLisxiogkTr88FXkdL8EDNigH".to_string()) + .debug_config(debug_config) + .request_gateway("FtR9Mb9y9EViYU3at6Qf7MzNHaMw8gofMicwqoscMBMP".to_string()) .build() .unwrap();