From b873f35f05f8deb195309d3f1a7466b171276bd8 Mon Sep 17 00:00:00 2001 From: sergerad Date: Mon, 24 Aug 2026 15:40:22 +1200 Subject: [PATCH 1/3] Distinguish grpc user errors from system errors --- Cargo.lock | 3 +- bin/ntx-builder/Cargo.toml | 1 - bin/ntx-builder/src/server.rs | 5 +- .../src/server/get_network_note_status.rs | 2 +- bin/remote-prover/Cargo.toml | 2 +- bin/remote-prover/src/server/mod.rs | 5 +- bin/remote-prover/src/server/prove.rs | 2 +- bin/remote-prover/src/server/prover.rs | 4 +- bin/remote-prover/src/server/service.rs | 2 +- bin/validator/Cargo.toml | 2 +- bin/validator/src/server/mod.rs | 5 +- .../validator_service/block_subscription.rs | 2 +- .../get_transaction_encryption_key.rs | 2 +- .../submit_proven_transaction.rs | 2 +- crates/block-producer/src/errors.rs | 3 + crates/block-producer/src/server/mod.rs | 8 +- crates/grpc-error-macro/Cargo.toml | 5 +- crates/grpc-error-macro/src/lib.rs | 117 ++++++--- crates/proto/src/errors/test_macro.rs | 43 ++++ crates/rpc/Cargo.toml | 1 - crates/rpc/src/server/api/get_account.rs | 2 +- .../rpc/src/server/api/get_block_by_number.rs | 2 +- .../server/api/get_block_header_by_number.rs | 2 +- crates/rpc/src/server/api/get_limits.rs | 2 +- .../src/server/api/get_network_note_status.rs | 2 +- .../src/server/api/get_note_script_by_root.rs | 2 +- crates/rpc/src/server/api/get_notes_by_id.rs | 2 +- .../api/get_transaction_encryption_key.rs | 2 +- crates/rpc/src/server/api/status.rs | 2 +- crates/rpc/src/server/api/submit_proven_tx.rs | 2 +- .../src/server/api/submit_proven_tx_batch.rs | 2 +- .../rpc/src/server/api/subscription/block.rs | 2 +- .../rpc/src/server/api/subscription/proof.rs | 2 +- .../server/api/sync_account_storage_maps.rs | 2 +- .../rpc/src/server/api/sync_account_vault.rs | 2 +- crates/rpc/src/server/api/sync_chain_mmr.rs | 2 +- crates/rpc/src/server/api/sync_notes.rs | 2 +- crates/rpc/src/server/api/sync_nullifiers.rs | 2 +- .../rpc/src/server/api/sync_transactions.rs | 2 +- crates/rpc/src/server/mod.rs | 18 +- crates/tracing-macro/src/lib.rs | 95 ++++++- crates/utils/Cargo.toml | 2 +- crates/utils/src/tracing/grpc.rs | 231 ++++++++++++++++++ crates/utils/src/tracing/mod.rs | 1 + crates/utils/tests/tracing_macros.rs | 105 ++++++++ .../ui/tracing_macros/grpc_err_with_err.rs | 8 + .../tracing_macros/grpc_err_with_err.stderr | 5 + 47 files changed, 621 insertions(+), 98 deletions(-) create mode 100644 crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs create mode 100644 crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr diff --git a/Cargo.lock b/Cargo.lock index b6e14704a2..6c97a97137 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4264,6 +4264,7 @@ dependencies = [ name = "miden-node-grpc-error-macro" version = "0.16.0-rc.1" dependencies = [ + "proc-macro2", "quote", "syn 2.0.119", ] @@ -4340,7 +4341,6 @@ dependencies = [ "tonic-reflection", "tonic-web", "tower", - "tower-http", "tracing", "url", ] @@ -4478,7 +4478,6 @@ dependencies = [ "tokio-stream", "tonic", "tonic-reflection", - "tower-http", "tracing", "url", ] diff --git a/bin/ntx-builder/Cargo.toml b/bin/ntx-builder/Cargo.toml index 36574d865e..1134a4ae74 100644 --- a/bin/ntx-builder/Cargo.toml +++ b/bin/ntx-builder/Cargo.toml @@ -36,7 +36,6 @@ tokio = { features = ["macros", "net", "rt-multi-thread"], work tokio-stream = { features = ["net"], workspace = true } tonic = { workspace = true } tonic-reflection = { workspace = true } -tower-http = { workspace = true } tracing = { workspace = true } url = { workspace = true } diff --git a/bin/ntx-builder/src/server.rs b/bin/ntx-builder/src/server.rs index a84df05d22..f7e5360046 100644 --- a/bin/ntx-builder/src/server.rs +++ b/bin/ntx-builder/src/server.rs @@ -3,11 +3,10 @@ use miden_node_proto::server::ntx_builder_api; use miden_node_proto_build::ntx_builder_api_descriptor; use miden_node_utils::panic::{CatchPanicLayer, catch_panic_layer_fn}; use miden_node_utils::shutdown::CancellationToken; -use miden_node_utils::tracing::grpc::grpc_trace_fn; +use miden_node_utils::tracing::grpc::grpc_trace_layer; use tokio::net::TcpListener; use tokio_stream::wrappers::TcpListenerStream; use tonic_reflection::server; -use tower_http::trace::TraceLayer; use crate::LOG_TARGET; use crate::db::NtxDbReader; @@ -57,7 +56,7 @@ impl NtxBuilderRpcServer { tonic::transport::Server::builder() .layer(CatchPanicLayer::custom(catch_panic_layer_fn)) - .layer(TraceLayer::new_for_grpc().make_span_with(grpc_trace_fn)) + .layer(grpc_trace_layer()) .add_service(api_service) .add_service(reflection_service) .serve_with_incoming_shutdown( diff --git a/bin/ntx-builder/src/server/get_network_note_status.rs b/bin/ntx-builder/src/server/get_network_note_status.rs index 555634df6a..4a4137da5b 100644 --- a/bin/ntx-builder/src/server/get_network_note_status.rs +++ b/bin/ntx-builder/src/server/get_network_note_status.rs @@ -26,7 +26,7 @@ impl grpc::server::ntx_builder_api::GetNetworkNoteStatus for NtxBuilderRpcServer fields ( note.id = %note_id, ), - err, + grpc_err, )] async fn handle( &self, diff --git a/bin/remote-prover/Cargo.toml b/bin/remote-prover/Cargo.toml index dd4f657ad4..2b5a0915a3 100644 --- a/bin/remote-prover/Cargo.toml +++ b/bin/remote-prover/Cargo.toml @@ -31,7 +31,7 @@ tonic = { default-features = false, features = ["codegen", "rou tonic-health = { workspace = true } tonic-reflection = { workspace = true } tonic-web = { workspace = true } -tower-http = { features = ["trace"], workspace = true } +tower-http = { features = ["catch-panic"], workspace = true } tracing = { workspace = true } [dev-dependencies] diff --git a/bin/remote-prover/src/server/mod.rs b/bin/remote-prover/src/server/mod.rs index fa4c089704..2c19591df7 100644 --- a/bin/remote-prover/src/server/mod.rs +++ b/bin/remote-prover/src/server/mod.rs @@ -6,14 +6,13 @@ use miden_node_utils::cors::cors_for_grpc_web_layer; use miden_node_utils::logging::OpenTelemetry; use miden_node_utils::panic::catch_panic_layer_fn; use miden_node_utils::shutdown::CancellationToken; -use miden_node_utils::tracing::grpc::grpc_trace_fn; +use miden_node_utils::tracing::grpc::grpc_trace_layer; use proof_kind::ProofKind; use tokio::net::TcpListener; use tokio::task::JoinHandle; use tokio_stream::wrappers::TcpListenerStream; use tonic_web::GrpcWebLayer; use tower_http::catch_panic::CatchPanicLayer; -use tower_http::trace::TraceLayer; use crate::LOG_TARGET; use crate::server::service::ProverService; @@ -109,7 +108,7 @@ impl Server { .accept_http1(true) .timeout(self.timeout) .layer(CatchPanicLayer::custom(catch_panic_layer_fn)) - .layer(TraceLayer::new_for_grpc().make_span_with(grpc_trace_fn)) + .layer(grpc_trace_layer()) .layer(cors_for_grpc_web_layer()) .layer(GrpcWebLayer::new()) .add_service(prover_service) diff --git a/bin/remote-prover/src/server/prove.rs b/bin/remote-prover/src/server/prove.rs index d23d7957f2..94e3814072 100644 --- a/bin/remote-prover/src/server/prove.rs +++ b/bin/remote-prover/src/server/prove.rs @@ -15,7 +15,7 @@ impl grpc::server::remote_prover_api::Prove for ProverService { #[miden_instrument( target = COMPONENT, name = "remote_prover.prove", - err, + grpc_err, )] async fn handle( &self, diff --git a/bin/remote-prover/src/server/prover.rs b/bin/remote-prover/src/server/prover.rs index f05b6120b4..b61db94ff7 100644 --- a/bin/remote-prover/src/server/prover.rs +++ b/bin/remote-prover/src/server/prover.rs @@ -71,7 +71,7 @@ trait ProveRequest: Send + Sync { #[miden_instrument( target=COMPONENT, name="prove", - err, + grpc_err, )] fn prove_request(&self, request: proto::ProofRequest) -> Result { let input = Self::decode_request(request)?; @@ -80,7 +80,7 @@ trait ProveRequest: Send + Sync { #[miden_instrument( target=COMPONENT, - err, + grpc_err, )] fn decode_request(request: proto::ProofRequest) -> Result { use miden_protocol::utils::serde::Deserializable; diff --git a/bin/remote-prover/src/server/service.rs b/bin/remote-prover/src/server/service.rs index fa70e7ff7f..ee81d4db19 100644 --- a/bin/remote-prover/src/server/service.rs +++ b/bin/remote-prover/src/server/service.rs @@ -27,7 +27,7 @@ impl ProverService { #[miden_instrument( target=COMPONENT, - err, + grpc_err, )] pub(super) fn acquire_permit(&self) -> Result { Arc::clone(&self.permits) diff --git a/bin/validator/Cargo.toml b/bin/validator/Cargo.toml index 24cd2c285c..90041a8fd6 100644 --- a/bin/validator/Cargo.toml +++ b/bin/validator/Cargo.toml @@ -51,7 +51,7 @@ tokio-stream = { features = ["net"], workspace = true } toml = { workspace = true } tonic = { default-features = true, features = ["transport"], workspace = true } tonic-reflection = { workspace = true } -tower-http = { features = ["util"], workspace = true } +tower-http = { features = ["catch-panic"], workspace = true } tracing = { workspace = true } zeroize = { workspace = true } diff --git a/bin/validator/src/server/mod.rs b/bin/validator/src/server/mod.rs index ac7954342a..b63909d167 100644 --- a/bin/validator/src/server/mod.rs +++ b/bin/validator/src/server/mod.rs @@ -7,11 +7,10 @@ use miden_node_store::BlockStore; use miden_node_utils::clap::GrpcOptions; use miden_node_utils::panic::catch_panic_layer_fn; use miden_node_utils::shutdown::CancellationToken; -use miden_node_utils::tracing::grpc::grpc_trace_fn; +use miden_node_utils::tracing::grpc::grpc_trace_layer; use tokio::net::TcpListener; use tokio_stream::wrappers::TcpListenerStream; use tower_http::catch_panic::CatchPanicLayer; -use tower_http::trace::TraceLayer; use crate::db::{ValidatorDbReader, ValidatorDbWriter}; use crate::{ @@ -153,7 +152,7 @@ impl ValidatorServer { // Build the gRPC server with the API service and trace layer. tonic::transport::Server::builder() .layer(CatchPanicLayer::custom(catch_panic_layer_fn)) - .layer(TraceLayer::new_for_grpc().make_span_with(grpc_trace_fn)) + .layer(grpc_trace_layer()) .timeout(self.grpc_options.request_timeout) .add_service(validator_api::service(service)) .add_service(reflection_service) diff --git a/bin/validator/src/server/validator_service/block_subscription.rs b/bin/validator/src/server/validator_service/block_subscription.rs index 2c1157726e..70fc4719b3 100644 --- a/bin/validator/src/server/validator_service/block_subscription.rs +++ b/bin/validator/src/server/validator_service/block_subscription.rs @@ -48,7 +48,7 @@ impl grpc::server::validator_api::BlockSubscription for ValidatorService { #[miden_instrument( target = COMPONENT, name = "validator.block_subscription", - err, + grpc_err, )] async fn handle( &self, diff --git a/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs b/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs index 4efcb1cf07..366508647b 100644 --- a/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs +++ b/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs @@ -21,7 +21,7 @@ impl grpc::server::validator_api::GetTransactionEncryptionKey for ValidatorServi #[miden_instrument( target = COMPONENT, name = "get_transaction_encryption_key", - err, + grpc_err, )] async fn handle( &self, diff --git a/bin/validator/src/server/validator_service/submit_proven_transaction.rs b/bin/validator/src/server/validator_service/submit_proven_transaction.rs index aef890ca3e..e1cc7e6e9d 100644 --- a/bin/validator/src/server/validator_service/submit_proven_transaction.rs +++ b/bin/validator/src/server/validator_service/submit_proven_transaction.rs @@ -23,7 +23,7 @@ impl grpc::server::validator_api::SubmitProvenTransaction for ValidatorService { #[miden_instrument( target = COMPONENT, name = "submit_proven_transaction", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/block-producer/src/errors.rs b/crates/block-producer/src/errors.rs index 949d0de431..5a3166cd3d 100644 --- a/crates/block-producer/src/errors.rs +++ b/crates/block-producer/src/errors.rs @@ -62,15 +62,18 @@ pub enum MempoolSubmissionError { #[error( "transaction expired at block height {expired_at} but the block height limit was {limit}" )] + #[grpc(failed_precondition)] Expired { expired_at: BlockNumber, limit: BlockNumber, }, #[error("transaction conflicts with current mempool state")] + #[grpc(failed_precondition)] StateConflict(#[source] StateConflict), #[error("the mempool is at capacity")] + #[grpc(resource_exhausted)] CapacityExceeded, #[error("mempool lock is poisoned")] diff --git a/crates/block-producer/src/server/mod.rs b/crates/block-producer/src/server/mod.rs index 820f327aa6..fee2772641 100644 --- a/crates/block-producer/src/server/mod.rs +++ b/crates/block-producer/src/server/mod.rs @@ -311,7 +311,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_proven_tx", - err, + grpc_err, )] pub async fn submit_proven_tx( &self, @@ -344,7 +344,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_authenticated_tx", - err, + grpc_err, )] #[expect(clippy::let_and_return, reason = "required to lengthen arc lifetime")] pub async fn submit_authenticated_tx( @@ -363,7 +363,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_proven_tx_batch", - err, + grpc_err, )] pub async fn submit_proven_tx_batch( &self, @@ -395,7 +395,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_authenticated_tx_batch", - err, + grpc_err, )] #[expect(clippy::let_and_return)] pub async fn submit_authenticated_tx_batch( diff --git a/crates/grpc-error-macro/Cargo.toml b/crates/grpc-error-macro/Cargo.toml index 8aab94e1e7..5cc623d11b 100644 --- a/crates/grpc-error-macro/Cargo.toml +++ b/crates/grpc-error-macro/Cargo.toml @@ -20,5 +20,6 @@ proc-macro = true test = false [dependencies] -quote = { workspace = true } -syn = { features = ["full"], workspace = true } +proc-macro2 = { workspace = true } +quote = { workspace = true } +syn = { features = ["full"], workspace = true } diff --git a/crates/grpc-error-macro/src/lib.rs b/crates/grpc-error-macro/src/lib.rs index e8cf194e02..a455866984 100644 --- a/crates/grpc-error-macro/src/lib.rs +++ b/crates/grpc-error-macro/src/lib.rs @@ -34,8 +34,10 @@ use syn::{Data, DeriveInput, Fields, Ident, parse_macro_input}; /// /// # Attributes /// -/// - `#[grpc(internal)]` - Marks a variant as an internal error (will map to -/// `tonic::Code::Internal`) +/// - `#[grpc()]` - Sets the variant's gRPC status code: `internal`, `invalid_argument`, +/// `not_found`, `failed_precondition` or `resource_exhausted`. Variants without the attribute +/// map to `invalid_argument`. Internal variants collapse into a shared `Internal` companion +/// variant and their message is masked as `"Internal error"`. /// /// # Generated Code /// @@ -64,6 +66,7 @@ pub fn derive_grpc_error(input: TokenStream) -> TokenStream { // Build the GrpcError enum variants let mut grpc_variants = Vec::new(); let mut api_error_arms = Vec::new(); + let mut tonic_code_arms = Vec::new(); // Always add Internal variant (standard practice for gRPC errors) grpc_variants.push(quote! { @@ -75,45 +78,43 @@ pub fn derive_grpc_error(input: TokenStream) -> TokenStream { for variant in variants { let variant_name = &variant.ident; - // Check if this variant is marked as internal - let is_internal = variant.attrs.iter().any(|attr| { - attr.path().is_ident("grpc") - && attr.parse_args::().is_ok_and(|i| i == "internal") - }); + // Parse the variant's `#[grpc()]` attribute; absent means `invalid_argument`. + let code = match variant_grpc_code(variant) { + Ok(code) => code, + Err(error) => return error.to_compile_error().into(), + }; // Extract doc comments let docs: Vec<_> = variant.attrs.iter().filter(|attr| attr.path().is_ident("doc")).collect(); - if is_internal { - // Map to Internal variant - let pattern = match &variant.fields { - Fields::Unit => quote! { #name::#variant_name }, - Fields::Unnamed(_) => quote! { #name::#variant_name(..) }, - Fields::Named(_) => quote! { #name::#variant_name { .. } }, - }; + let pattern = match &variant.fields { + Fields::Unit => quote! { #name::#variant_name }, + Fields::Unnamed(_) => quote! { #name::#variant_name(..) }, + Fields::Named(_) => quote! { #name::#variant_name { .. } }, + }; - api_error_arms.push(quote! { - #pattern => #grpc_name::Internal - }); - } else { + if let Some(tonic_code) = code.tonic_code_ident() { // Create a corresponding variant in GrpcError enum grpc_variants.push(quote! { #(#docs)* #variant_name = #discriminant }); - let pattern = match &variant.fields { - Fields::Unit => quote! { #name::#variant_name }, - Fields::Unnamed(_) => quote! { #name::#variant_name(..) }, - Fields::Named(_) => quote! { #name::#variant_name { .. } }, - }; - api_error_arms.push(quote! { #pattern => #grpc_name::#variant_name }); + tonic_code_arms.push(quote! { + Self::#variant_name => tonic::Code::#tonic_code + }); + discriminant += 1; + } else { + // Map to Internal variant + api_error_arms.push(quote! { + #pattern => #grpc_name::Internal + }); } } @@ -137,10 +138,9 @@ pub fn derive_grpc_error(input: TokenStream) -> TokenStream { /// Returns the appropriate tonic code for this error. pub fn tonic_code(&self) -> tonic::Code { - if self.is_internal() { - tonic::Code::Internal - } else { - tonic::Code::InvalidArgument + match self { + Self::Internal => tonic::Code::Internal, + #(#tonic_code_arms,)* } } } @@ -174,7 +174,68 @@ pub fn derive_grpc_error(input: TokenStream) -> TokenStream { ) } } + + impl ::miden_node_utils::tracing::GrpcFault for #name { + fn is_server_fault(&self) -> bool { + ::miden_node_utils::tracing::is_server_fault_code(self.api_error().tonic_code()) + } + } }; TokenStream::from(expanded) } + +/// The gRPC code assigned to an error variant via `#[grpc()]`. +#[derive(Clone, Copy)] +enum GrpcVariantCode { + Internal, + InvalidArgument, + NotFound, + FailedPrecondition, + ResourceExhausted, +} + +impl GrpcVariantCode { + /// The identifier of the corresponding `tonic::Code` variant. + /// + /// `None` for internal errors, which collapse into the companion enum's `Internal` variant. + fn tonic_code_ident(self) -> Option { + let name = match self { + Self::Internal => return None, + Self::InvalidArgument => "InvalidArgument", + Self::NotFound => "NotFound", + Self::FailedPrecondition => "FailedPrecondition", + Self::ResourceExhausted => "ResourceExhausted", + }; + Some(Ident::new(name, proc_macro2::Span::call_site())) + } +} + +/// Parses a variant's `#[grpc()]` attribute; a variant without one maps to +/// `invalid_argument`. +fn variant_grpc_code(variant: &syn::Variant) -> syn::Result { + let mut code = GrpcVariantCode::InvalidArgument; + for attr in &variant.attrs { + if !attr.path().is_ident("grpc") { + continue; + } + let ident: Ident = attr.parse_args()?; + code = match ident.to_string().as_str() { + "internal" => GrpcVariantCode::Internal, + "invalid_argument" => GrpcVariantCode::InvalidArgument, + "not_found" => GrpcVariantCode::NotFound, + "failed_precondition" => GrpcVariantCode::FailedPrecondition, + "resource_exhausted" => GrpcVariantCode::ResourceExhausted, + other => { + return Err(syn::Error::new_spanned( + &ident, + format!( + "unsupported gRPC code `{other}`; use one of: internal, \ + invalid_argument, not_found, failed_precondition, resource_exhausted" + ), + )); + }, + }; + } + Ok(code) +} diff --git a/crates/proto/src/errors/test_macro.rs b/crates/proto/src/errors/test_macro.rs index abfc9ddcc1..97a2586966 100644 --- a/crates/proto/src/errors/test_macro.rs +++ b/crates/proto/src/errors/test_macro.rs @@ -22,6 +22,18 @@ pub enum TestError { #[error("client error 3")] ClientError3, + + #[error("not found")] + #[grpc(not_found)] + NotFoundError, + + #[error("failed precondition")] + #[grpc(failed_precondition)] + PreconditionError, + + #[error("resource exhausted")] + #[grpc(resource_exhausted)] + ExhaustedError, } #[cfg(test)] @@ -66,4 +78,35 @@ mod tests { assert_eq!(client_status.code(), tonic::Code::InvalidArgument); assert_eq!(client_status.message(), "client error 1"); } + + #[test] + fn test_explicit_grpc_codes() { + // Explicitly coded variants keep their own companion variant and discriminant but map to + // the requested tonic code with an unmasked message. + assert_eq!(TestErrorGrpcError::NotFoundError.api_code(), 4); + assert_eq!(TestErrorGrpcError::PreconditionError.api_code(), 5); + assert_eq!(TestErrorGrpcError::ExhaustedError.api_code(), 6); + + let status: tonic::Status = TestError::NotFoundError.into(); + assert_eq!(status.code(), tonic::Code::NotFound); + assert_eq!(status.message(), "not found"); + + let status: tonic::Status = TestError::PreconditionError.into(); + assert_eq!(status.code(), tonic::Code::FailedPrecondition); + + let status: tonic::Status = TestError::ExhaustedError.into(); + assert_eq!(status.code(), tonic::Code::ResourceExhausted); + } + + #[test] + fn test_grpc_fault_classification() { + use miden_node_utils::tracing::GrpcFault; + + // Only internal errors indicate a node fault; client-caused codes do not. + assert!(TestError::InternalError1.is_server_fault()); + assert!(!TestError::ClientError1.is_server_fault()); + assert!(!TestError::NotFoundError.is_server_fault()); + assert!(!TestError::PreconditionError.is_server_fault()); + assert!(!TestError::ExhaustedError.is_server_fault()); + } } diff --git a/crates/rpc/Cargo.toml b/crates/rpc/Cargo.toml index ba46255c08..46ff0e15e5 100644 --- a/crates/rpc/Cargo.toml +++ b/crates/rpc/Cargo.toml @@ -39,7 +39,6 @@ tonic-health = { workspace = true } tonic-reflection = { workspace = true } tonic-web = { workspace = true } tower = { workspace = true } -tower-http = { features = ["trace"], workspace = true } tracing = { workspace = true } url = { workspace = true } diff --git a/crates/rpc/src/server/api/get_account.rs b/crates/rpc/src/server/api/get_account.rs index 2e38d528f1..879fbd99f1 100644 --- a/crates/rpc/src/server/api/get_account.rs +++ b/crates/rpc/src/server/api/get_account.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::GetAccount for RpcService { #[miden_instrument( target = COMPONENT, name = "get_account", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_block_by_number.rs b/crates/rpc/src/server/api/get_block_by_number.rs index 49af795256..36bf267db6 100644 --- a/crates/rpc/src/server/api/get_block_by_number.rs +++ b/crates/rpc/src/server/api/get_block_by_number.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::GetBlockByNumber for RpcService { fields( block.number = %request.block_num, ), - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_block_header_by_number.rs b/crates/rpc/src/server/api/get_block_header_by_number.rs index 6d1525a80f..26fdf880fd 100644 --- a/crates/rpc/src/server/api/get_block_header_by_number.rs +++ b/crates/rpc/src/server/api/get_block_header_by_number.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::GetBlockHeaderByNumber for RpcService { fields( block.number = %request.block_num(), ), - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_limits.rs b/crates/rpc/src/server/api/get_limits.rs index 5d35a86e4b..a67e515017 100644 --- a/crates/rpc/src/server/api/get_limits.rs +++ b/crates/rpc/src/server/api/get_limits.rs @@ -21,7 +21,7 @@ impl proto::server::rpc_api::GetLimits for RpcService { #[miden_instrument( target = COMPONENT, name = "get_limits", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_network_note_status.rs b/crates/rpc/src/server/api/get_network_note_status.rs index df38e1693d..852646249e 100644 --- a/crates/rpc/src/server/api/get_network_note_status.rs +++ b/crates/rpc/src/server/api/get_network_note_status.rs @@ -29,7 +29,7 @@ impl proto::server::rpc_api::GetNetworkNoteStatus for RpcService { #[miden_instrument( target = COMPONENT, name = "get_network_note_status", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_note_script_by_root.rs b/crates/rpc/src/server/api/get_note_script_by_root.rs index 1b955b7d07..01061d96e3 100644 --- a/crates/rpc/src/server/api/get_note_script_by_root.rs +++ b/crates/rpc/src/server/api/get_note_script_by_root.rs @@ -24,7 +24,7 @@ impl proto::server::rpc_api::GetNoteScriptByRoot for RpcService { #[miden_instrument( target = COMPONENT, name = "get_note_script_by_root", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_notes_by_id.rs b/crates/rpc/src/server/api/get_notes_by_id.rs index bcbc6bcb90..8906e7e0bb 100644 --- a/crates/rpc/src/server/api/get_notes_by_id.rs +++ b/crates/rpc/src/server/api/get_notes_by_id.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::GetNotesById for RpcService { #[miden_instrument( target = COMPONENT, name = "get_notes_by_id", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_transaction_encryption_key.rs b/crates/rpc/src/server/api/get_transaction_encryption_key.rs index ec1ff9c560..bb7e4a9f63 100644 --- a/crates/rpc/src/server/api/get_transaction_encryption_key.rs +++ b/crates/rpc/src/server/api/get_transaction_encryption_key.rs @@ -21,7 +21,7 @@ impl proto::server::rpc_api::GetTransactionEncryptionKey for RpcService { #[miden_instrument( target = COMPONENT, name = "get_transaction_encryption_key", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/status.rs b/crates/rpc/src/server/api/status.rs index d8b67a5ce7..7de32a9a21 100644 --- a/crates/rpc/src/server/api/status.rs +++ b/crates/rpc/src/server/api/status.rs @@ -22,7 +22,7 @@ impl proto::server::rpc_api::Status for RpcService { #[miden_instrument( target = COMPONENT, name = "status", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/submit_proven_tx.rs b/crates/rpc/src/server/api/submit_proven_tx.rs index 65ae7a1932..7e5163e4c8 100644 --- a/crates/rpc/src/server/api/submit_proven_tx.rs +++ b/crates/rpc/src/server/api/submit_proven_tx.rs @@ -36,7 +36,7 @@ impl proto::server::rpc_api::SubmitProvenTx for RpcService { #[miden_instrument( target = COMPONENT, name = "submit_proven_tx", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/submit_proven_tx_batch.rs b/crates/rpc/src/server/api/submit_proven_tx_batch.rs index c8ea58ca3e..af55ae15a6 100644 --- a/crates/rpc/src/server/api/submit_proven_tx_batch.rs +++ b/crates/rpc/src/server/api/submit_proven_tx_batch.rs @@ -29,7 +29,7 @@ impl proto::server::rpc_api::SubmitProvenTxBatch for RpcService { #[miden_instrument( target = COMPONENT, name = "submit_proven_tx_batch", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/subscription/block.rs b/crates/rpc/src/server/api/subscription/block.rs index ca2fc0978a..32f24fdb2a 100644 --- a/crates/rpc/src/server/api/subscription/block.rs +++ b/crates/rpc/src/server/api/subscription/block.rs @@ -31,7 +31,7 @@ impl proto::server::rpc_api::BlockSubscription for RpcService { fields( block.from = %input, ), - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/subscription/proof.rs b/crates/rpc/src/server/api/subscription/proof.rs index 300cd976c7..b01f7e9d6a 100644 --- a/crates/rpc/src/server/api/subscription/proof.rs +++ b/crates/rpc/src/server/api/subscription/proof.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::ProofSubscription for RpcService { fields( block.from = %input, ), - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_account_storage_maps.rs b/crates/rpc/src/server/api/sync_account_storage_maps.rs index 7ad0fcc6e3..25f359ffc1 100644 --- a/crates/rpc/src/server/api/sync_account_storage_maps.rs +++ b/crates/rpc/src/server/api/sync_account_storage_maps.rs @@ -27,7 +27,7 @@ impl proto::server::rpc_api::SyncAccountStorageMaps for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_account_storage_maps", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_account_vault.rs b/crates/rpc/src/server/api/sync_account_vault.rs index 44f238871b..3be6bb7449 100644 --- a/crates/rpc/src/server/api/sync_account_vault.rs +++ b/crates/rpc/src/server/api/sync_account_vault.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::SyncAccountVault for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_account_vault", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_chain_mmr.rs b/crates/rpc/src/server/api/sync_chain_mmr.rs index 1f3cea4f65..04e89a2131 100644 --- a/crates/rpc/src/server/api/sync_chain_mmr.rs +++ b/crates/rpc/src/server/api/sync_chain_mmr.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::SyncChainMmr for RpcService { current_client_block_height = %request.current_client_block_height, finality_level = %request.finality_level().as_str_name(), ), - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_notes.rs b/crates/rpc/src/server/api/sync_notes.rs index 48df263de3..2617d69d7b 100644 --- a/crates/rpc/src/server/api/sync_notes.rs +++ b/crates/rpc/src/server/api/sync_notes.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::SyncNotes for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_notes", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_nullifiers.rs b/crates/rpc/src/server/api/sync_nullifiers.rs index 82b6e7dc26..b4c688fb3c 100644 --- a/crates/rpc/src/server/api/sync_nullifiers.rs +++ b/crates/rpc/src/server/api/sync_nullifiers.rs @@ -30,7 +30,7 @@ impl proto::server::rpc_api::SyncNullifiers for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_nullifiers", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_transactions.rs b/crates/rpc/src/server/api/sync_transactions.rs index 984e9d7c84..348c72b0f9 100644 --- a/crates/rpc/src/server/api/sync_transactions.rs +++ b/crates/rpc/src/server/api/sync_transactions.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::SyncTransactions for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_transactions", - err, + grpc_err, )] async fn handle( &self, diff --git a/crates/rpc/src/server/mod.rs b/crates/rpc/src/server/mod.rs index 25e0e33af5..4db338d383 100644 --- a/crates/rpc/src/server/mod.rs +++ b/crates/rpc/src/server/mod.rs @@ -20,15 +20,13 @@ use miden_node_utils::grpc; use miden_node_utils::panic::{CatchPanicLayer, catch_panic_layer_fn}; use miden_node_utils::shutdown::CancellationToken; use miden_node_utils::tasks::Tasks; -use miden_node_utils::tracing::grpc::grpc_trace_fn; +use miden_node_utils::tracing::grpc::grpc_trace_layer; use rand::RngExt; use tokio::net::TcpListener; use tokio_stream::wrappers::TcpListenerStream; use tonic::metadata::AsciiMetadataValue; use tonic_reflection::server; use tonic_web::GrpcWebLayer; -use tower_http::classify::{GrpcCode, GrpcErrorsAsFailures, SharedClassifier}; -use tower_http::trace::TraceLayer; use tracing::info; use crate::LOG_TARGET; @@ -328,17 +326,7 @@ impl Rpc { .accept_http1(true) .timeout(self.grpc_options.request_timeout) .layer(CatchPanicLayer::custom(catch_panic_layer_fn)) - .layer( - TraceLayer::new(SharedClassifier::new( - GrpcErrorsAsFailures::new() - .with_success(GrpcCode::InvalidArgument) - .with_success(GrpcCode::NotFound) - .with_success(GrpcCode::ResourceExhausted) - .with_success(GrpcCode::Unimplemented) - .with_success(GrpcCode::Unknown), - )) - .make_span_with(grpc_trace_fn), - ) + .layer(grpc_trace_layer()) .layer(HealthCheckLayer) .layer(cors_for_grpc_web_layer()) // Note: must wrap the accept layer so grpc-web callers receive grpc-web-compatible @@ -474,7 +462,7 @@ impl SequencerInternal { // and is expected to be network-isolated. tonic::transport::Server::builder() .layer(CatchPanicLayer::custom(catch_panic_layer_fn)) - .layer(TraceLayer::new_for_grpc().make_span_with(grpc_trace_fn)) + .layer(grpc_trace_layer()) .timeout(self.grpc_options.request_timeout) .add_service(sequencer_api::service(service)) .serve_with_incoming_shutdown( diff --git a/crates/tracing-macro/src/lib.rs b/crates/tracing-macro/src/lib.rs index ee76b6ff61..7b102cd542 100644 --- a/crates/tracing-macro/src/lib.rs +++ b/crates/tracing-macro/src/lib.rs @@ -7,7 +7,7 @@ use syn::parse::{Parse, ParseStream}; use syn::punctuated::Punctuated; use syn::token::Dot; use syn::visit::Visit; -use syn::{Block, Expr, Ident, ItemFn, Macro, Result, Token, parse_macro_input, parse_quote}; +use syn::{Block, Expr, Ident, ItemFn, Macro, Result, Stmt, Token, parse_macro_input, parse_quote}; const ALLOWED_FIELD_NAMES: &[&str] = &[ "account.id", @@ -106,10 +106,13 @@ pub fn miden_instrument(attr: TokenStream, item: TokenStream) -> TokenStream { let attr = TokenStream2::from(attr); let mut function = parse_macro_input!(item as ItemFn); let fields = collect_recorded_fields(&function); - let args = match merge_inferred_fields(attr, &fields) { + let (args, grpc_err) = match merge_inferred_fields(attr, &fields) { Ok(args) => args, Err(error) => return error.into_compile_error().into(), }; + if grpc_err { + apply_grpc_err(&mut function); + } let statements = &function.block.stmts; let block: Block = parse_quote! {{ #[allow(unused_macros)] @@ -129,18 +132,19 @@ pub fn miden_instrument(attr: TokenStream, item: TokenStream) -> TokenStream { expanded.into() } -fn merge_inferred_fields(attr: TokenStream2, fields: &[FieldPath]) -> Result { +fn merge_inferred_fields(attr: TokenStream2, fields: &[FieldPath]) -> Result<(TokenStream2, bool)> { validate_explicit_fields(&attr)?; let mut args = split_top_level_args(attr); reject_skip_directives(&args)?; + let grpc_err = extract_grpc_err_directive(&mut args)?; // Function arguments often contain large or sensitive values. Always skip them so spans only // contain fields explicitly declared by the caller or inferred from `miden_span_record!`. args.push(quote! { skip_all }); if fields.is_empty() { - return Ok(quote! { #(#args),* }); + return Ok((quote! { #(#args),* }, grpc_err)); } let inferred_fields = quote! { #(#fields = ::tracing::field::Empty),* }; @@ -168,10 +172,89 @@ fn merge_inferred_fields(attr: TokenStream2, fields: &[FieldPath]) -> Result>(); if merged_existing_fields { - Ok(quote! { #(#args),* }) + Ok((quote! { #(#args),* }, grpc_err)) } else { - Ok(quote! { #(#args,)* fields(#inferred_fields) }) + Ok((quote! { #(#args,)* fields(#inferred_fields) }, grpc_err)) + } +} + +/// Rewrites the function body so a returned `Err` is classified via +/// `miden_node_utils::tracing::record_grpc_error` from inside the instrumented span: node faults +/// mark the span with `OTel` error status (like `err` would), while client-caused failures do not — +/// rejecting a bad request is the node behaving correctly, not an application error. +/// +/// `#[async_trait]` methods are expanded before this macro runs, leaving a non-async fn whose +/// body is `Box::pin(async move { ... })`; the classification is applied inside that async block +/// so it runs within the instrumented span. +fn apply_grpc_err(function: &mut ItemFn) { + fn classified(body: &TokenStream2) -> Block { + parse_quote! {{ + #[allow(clippy::redundant_async_block, clippy::redundant_closure_call)] + let __miden_instrument_result = #body; + if let Err(err) = &__miden_instrument_result { + ::miden_node_utils::tracing::record_grpc_error(err); + } + __miden_instrument_result + }} + } + + fn wrap_async(statements: &[Stmt]) -> Block { + classified("e! { async move { #(#statements)* }.await }) + } + + if function.sig.asyncness.is_some() { + let wrapped = wrap_async(&function.block.stmts); + *function.block = wrapped; + return; } + + if let Some(Stmt::Expr(Expr::Call(call), _)) = function.block.stmts.last_mut() + && call.args.len() == 1 + && let Some(Expr::Async(async_block)) = call.args.first_mut() + { + let wrapped = wrap_async(&async_block.block.stmts); + async_block.block = wrapped; + return; + } + + let statements = &function.block.stmts; + let wrapped = classified("e! { (move || { #(#statements)* })() }); + *function.block = wrapped; +} + +/// Removes the `grpc_err` directive from the argument list, returning whether it was present. +/// +/// `grpc_err` is a `miden_instrument` extension, not a `tracing::instrument` argument, so it must +/// not be forwarded. It replaces `err`: combining the two would double-report the error. +fn extract_grpc_err_directive(args: &mut Vec) -> Result { + let is_bare_ident = |arg: &TokenStream2, name: &str| { + let mut tokens = arg.clone().into_iter(); + matches!(tokens.next(), Some(TokenTree::Ident(ident)) if ident == name) + && tokens.next().is_none() + }; + + let mut grpc_err = false; + args.retain(|arg| { + let found = is_bare_ident(arg, "grpc_err"); + grpc_err |= found; + !found + }); + + if grpc_err { + for arg in args.iter() { + let Some(TokenTree::Ident(ident)) = arg.clone().into_iter().next() else { + continue; + }; + if ident == "err" { + return Err(syn::Error::new_spanned( + arg, + "`err` cannot be combined with `grpc_err`", + )); + } + } + } + + Ok(grpc_err) } fn reject_skip_directives(args: &[TokenStream2]) -> Result<()> { diff --git a/crates/utils/Cargo.toml b/crates/utils/Cargo.toml index 73d217877d..7f44ad7ee8 100644 --- a/crates/utils/Cargo.toml +++ b/crates/utils/Cargo.toml @@ -44,7 +44,7 @@ tokio = { features = ["macros", "rt", "signal", "time"], work tokio-util = { workspace = true } tonic = { default-features = true, workspace = true } tower = { workspace = true } -tower-http = { features = ["catch-panic"], workspace = true } +tower-http = { features = ["catch-panic", "trace"], workspace = true } tower_governor = { version = "0.8" } tracing = { workspace = true } tracing-forest = { features = ["chrono"], optional = true, version = "0.3" } diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index f3d367807c..2e36d5c0e7 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -1,7 +1,21 @@ +use std::time::Duration; + use http::header::HeaderName; use tower_governor::key_extractor::{KeyExtractor, SmartIpKeyExtractor}; +use tower_http::classify::{GrpcCode, GrpcErrorsAsFailures, GrpcFailureClass, SharedClassifier}; +use tower_http::trace::{DefaultOnBodyChunk, DefaultOnRequest, TraceLayer}; use tracing::field; +use super::ErrorSpanExt; + +/// The span field holding the numeric gRPC status code of the response, following the +/// [OTel RPC semantic conventions](https://opentelemetry.io/docs/specs/semconv/rpc/grpc/). +/// +/// Always recorded on request root spans: `0` (OK) on success, the actual code on failure. This +/// lets queries distinguish request outcomes without relying on the span's error status, which is +/// reserved for node faults (see [`is_server_fault_code`]). +const GRPC_STATUS_CODE_FIELD: &str = "rpc.grpc.status_code"; + /// Returns a [`trace_fn`](tonic::transport::server::Server) implementation for gRPC requests /// which adds open-telemetry information to the span. /// @@ -27,6 +41,7 @@ pub fn grpc_trace_fn(request: &http::Request) -> tracing::Span { rpc.system = field::Empty, rpc.request.size = field::Empty, rpc.response.size = field::Empty, + rpc.grpc.status_code = field::Empty, server.address = field::Empty, server.port = field::Empty, client.address = field::Empty, @@ -108,6 +123,184 @@ pub fn grpc_trace_fn(request: &http::Request) -> tracing::Span { span } +/// Returns whether a gRPC status code indicates a fault in the node, as opposed to a failure +/// caused by the request itself. +/// +/// Client-caused failures (invalid arguments, failed preconditions, exhausted quotas, ...) are +/// *successful rejections* and must not mark spans with `OTel` error status, otherwise client noise +/// becomes indistinguishable from node failures in error-based alerting. +/// +/// The set mirrors the [OTel gRPC semantic conventions] for server spans, except that +/// `UNIMPLEMENTED` is treated as client-caused: on a public API, calls to unknown methods are +/// client noise, not a node fault. +/// +/// [OTel gRPC semantic conventions]: https://opentelemetry.io/docs/specs/semconv/rpc/grpc/ +pub fn is_server_fault_code(code: tonic::Code) -> bool { + matches!( + code, + tonic::Code::Unknown + | tonic::Code::DeadlineExceeded + | tonic::Code::Internal + | tonic::Code::Unavailable + | tonic::Code::DataLoss + ) +} + +/// Classifies errors into node faults vs client-caused failures for telemetry purposes. +/// +/// Implemented by [`tonic::Status`] and by error enums deriving +/// `miden_node_proto::errors::GrpcError`. +pub trait GrpcFault { + /// Returns whether this error indicates a fault in the node rather than a bad request. + fn is_server_fault(&self) -> bool; +} + +impl GrpcFault for tonic::Status { + fn is_server_fault(&self) -> bool { + is_server_fault_code(self.code()) + } +} + +/// Records a request-handling error on the current span. +/// +/// Called by `miden_instrument`'s `grpc_err` directive. Node faults are logged at error level and +/// mark the span with `OTel` error status, matching the plain `err` directive; client-caused +/// failures are logged at debug level and leave the span status untouched, since rejecting a bad +/// request is the node behaving correctly. +pub fn record_grpc_error(err: &E) +where + E: GrpcFault + std::error::Error, +{ + use crate::ErrorReport; + + if err.is_server_fault() { + tracing::error!(error = err.as_report()); + tracing::Span::current().set_error(err); + } else { + tracing::debug!(error = err.as_report()); + } +} + +/// Returns the [`TraceLayer`] for gRPC servers. +/// +/// - Creates the per-request root span via [`grpc_trace_fn`]. +/// - Records `rpc.grpc.status_code` on every request span — `0` (OK) on success, the actual code +/// on failure — so request outcomes are always queryable. +/// - Marks the span with `OTel` error status only for codes indicating a node fault (see +/// [`is_server_fault_code`]); client-caused failures keep the span status unset. +pub fn grpc_trace_layer() -> TraceLayer< + SharedClassifier, + GrpcMakeSpan, + DefaultOnRequest, + GrpcOnResponse, + DefaultOnBodyChunk, + GrpcOnEos, + GrpcOnFailure, +> { + TraceLayer::new(SharedClassifier::new(grpc_fault_classifier())) + .make_span_with(GrpcMakeSpan) + .on_response(GrpcOnResponse) + .on_eos(GrpcOnEos) + .on_failure(GrpcOnFailure) +} + +/// Returns the response classifier used by [`grpc_trace_layer`]. +/// +/// The complement of [`is_server_fault_code`]: client-caused codes are classified as successes so +/// they never reach [`GrpcOnFailure`]. +fn grpc_fault_classifier() -> GrpcErrorsAsFailures { + GrpcErrorsAsFailures::new() + .with_success(GrpcCode::Cancelled) + .with_success(GrpcCode::InvalidArgument) + .with_success(GrpcCode::NotFound) + .with_success(GrpcCode::AlreadyExists) + .with_success(GrpcCode::PermissionDenied) + .with_success(GrpcCode::ResourceExhausted) + .with_success(GrpcCode::FailedPrecondition) + .with_success(GrpcCode::Aborted) + .with_success(GrpcCode::OutOfRange) + .with_success(GrpcCode::Unimplemented) + .with_success(GrpcCode::Unauthenticated) +} + +/// [`tower_http::trace::MakeSpan`] implementation wrapping [`grpc_trace_fn`]. +#[derive(Clone, Copy, Debug)] +pub struct GrpcMakeSpan; + +impl tower_http::trace::MakeSpan for GrpcMakeSpan { + fn make_span(&mut self, request: &http::Request) -> tracing::Span { + grpc_trace_fn(request) + } +} + +/// Records the gRPC status code carried in the response headers (tonic sends error statuses as +/// "trailers-only" responses, i.e. in the headers). +/// +/// When the header is absent the status arrives in the trailers instead; `OK` is recorded +/// provisionally so the field is always present, and [`GrpcOnEos`] / [`GrpcOnFailure`] overwrite +/// it with the actual code once known. +#[derive(Clone, Copy, Debug)] +pub struct GrpcOnResponse; + +impl tower_http::trace::OnResponse for GrpcOnResponse { + fn on_response(self, response: &http::Response, _latency: Duration, span: &tracing::Span) { + let code = grpc_status_from_headers(response.headers()).unwrap_or(0); + span.record(GRPC_STATUS_CODE_FIELD, code); + } +} + +/// Records the gRPC status code from the response trailers at end-of-stream. +#[derive(Clone, Copy, Debug)] +pub struct GrpcOnEos; + +impl tower_http::trace::OnEos for GrpcOnEos { + fn on_eos( + self, + trailers: Option<&http::HeaderMap>, + _stream_duration: Duration, + span: &tracing::Span, + ) { + if let Some(code) = trailers.and_then(grpc_status_from_headers) { + span.record(GRPC_STATUS_CODE_FIELD, code); + } + } +} + +/// Marks the request span as failed. +/// +/// Only invoked for classifications indicating a node fault (see [`grpc_trace_layer`]); +/// client-caused failures never reach this. +#[derive(Clone, Debug)] +pub struct GrpcOnFailure; + +impl tower_http::trace::OnFailure for GrpcOnFailure { + fn on_failure( + &mut self, + classification: GrpcFailureClass, + latency: Duration, + span: &tracing::Span, + ) { + let code = match &classification { + GrpcFailureClass::Code(code) => code.get(), + // Transport-level failure without a gRPC status; map to `UNKNOWN`. + GrpcFailureClass::Error(_) => tonic::Code::Unknown as i32, + }; + span.record(GRPC_STATUS_CODE_FIELD, code); + tracing_opentelemetry::OpenTelemetrySpanExt::set_status( + span, + opentelemetry::trace::Status::Error { + description: classification.to_string().into(), + }, + ); + tracing::error!(classification = %classification, latency = ?latency, "request failed"); + } +} + +/// Parses the numeric `grpc-status` code from a header or trailer map. +fn grpc_status_from_headers(headers: &http::HeaderMap) -> Option { + headers.get("grpc-status")?.to_str().ok()?.parse().ok() +} + /// Injects open-telemetry remote context into traces. #[derive(Copy, Clone)] pub struct OtelInterceptor; @@ -159,3 +352,41 @@ impl opentelemetry::propagation::Injector for MetadataInjector<'_> { } } } + +#[cfg(test)] +mod tests { + use tower_http::classify::{ClassifiedResponse, ClassifyResponse}; + + use super::*; + + #[test] + fn parses_grpc_status_header() { + let mut headers = http::HeaderMap::new(); + assert_eq!(grpc_status_from_headers(&headers), None); + + headers.insert("grpc-status", "3".parse().unwrap()); + assert_eq!(grpc_status_from_headers(&headers), Some(3)); + } + + /// The trace layer's classifier decides which responses mark the request span as an error; it + /// must agree with [`is_server_fault_code`], which drives the same decision for handler spans + /// via `grpc_err`. + #[test] + fn classifier_agrees_with_fault_classification() { + // 0..=16 covers every gRPC status code. + for code in 0..=16i32 { + let response = http::Response::builder() + .header("grpc-status", code.to_string()) + .body(()) + .unwrap(); + + let classified_as_failure = matches!( + grpc_fault_classifier().classify_response(&response), + ClassifiedResponse::Ready(Err(_)) + ); + let is_fault = code != 0 && is_server_fault_code(tonic::Code::from(code)); + + assert_eq!(classified_as_failure, is_fault, "gRPC code {code}"); + } + } +} diff --git a/crates/utils/src/tracing/mod.rs b/crates/utils/src/tracing/mod.rs index 20f4dc6c1e..e6e5880e54 100644 --- a/crates/utils/src/tracing/mod.rs +++ b/crates/utils/src/tracing/mod.rs @@ -1,5 +1,6 @@ pub mod grpc; mod span_ext; +pub use grpc::{GrpcFault, is_server_fault_code, record_grpc_error}; pub use miden_node_tracing_macro::{miden_instrument, miden_span_record}; pub use span_ext::ErrorSpanExt; diff --git a/crates/utils/tests/tracing_macros.rs b/crates/utils/tests/tracing_macros.rs index 9e5f71b1d5..6888ed0901 100644 --- a/crates/utils/tests/tracing_macros.rs +++ b/crates/utils/tests/tracing_macros.rs @@ -49,6 +49,25 @@ impl Visit for FieldVisitor { } } +#[derive(Clone, Default)] +struct RecordedEventLevels(Arc>>); + +impl RecordedEventLevels { + fn contains(&self, level: tracing::Level) -> bool { + self.0.lock().unwrap().contains(&level) + } +} + +impl Layer for RecordedEventLevels +where + S: Subscriber, + for<'a> S: LookupSpan<'a>, +{ + fn on_event(&self, event: &tracing::Event<'_>, _ctx: Context<'_, S>) { + self.0.lock().unwrap().push(*event.metadata().level()); + } +} + #[miden_instrument(target = "miden-node-utils-test", name = "records_delayed_fields")] fn records_inferred_fields() { let parsed_value = 42; @@ -167,6 +186,91 @@ fn multiple_span_record_macros_can_record_fields_after_span_creation() { assert_eq!(recorded.get("transaction.id").as_deref(), Some("multi-call-tx")); } +#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_client_fault", grpc_err)] +async fn grpc_err_client_fault() -> Result<(), tonic::Status> { + Err(tonic::Status::invalid_argument("bad request")) +} + +#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_server_fault", grpc_err)] +async fn grpc_err_server_fault() -> Result<(), tonic::Status> { + Err(tonic::Status::internal("node fault")) +} + +#[tonic::async_trait] +trait GrpcErrHandler { + async fn handle(&self, fail: bool) -> Result<(), tonic::Status>; +} + +struct AsyncTraitHandler; + +#[tonic::async_trait] +impl GrpcErrHandler for AsyncTraitHandler { + #[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_async_trait", grpc_err)] + async fn handle(&self, fail: bool) -> Result<(), tonic::Status> { + if fail { + return Err(tonic::Status::internal("node fault")); + } + Ok(()) + } +} + +#[tokio::test] +async fn grpc_err_client_faults_are_not_error_events() { + let events = RecordedEventLevels::default(); + let subscriber = tracing_subscriber::registry().with(events.clone()); + let _guard = tracing::subscriber::set_default(subscriber); + + grpc_err_client_fault().await.unwrap_err(); + + assert!(events.contains(tracing::Level::DEBUG)); + assert!(!events.contains(tracing::Level::ERROR)); +} + +#[tokio::test] +async fn grpc_err_server_faults_are_error_events() { + let events = RecordedEventLevels::default(); + let subscriber = tracing_subscriber::registry().with(events.clone()); + let _guard = tracing::subscriber::set_default(subscriber); + + grpc_err_server_fault().await.unwrap_err(); + + assert!(events.contains(tracing::Level::ERROR)); +} + +#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_sync", grpc_err)] +fn grpc_err_sync(fail: bool) -> Result<(), tonic::Status> { + if fail { + return Err(tonic::Status::internal("node fault")); + } + Ok(()) +} + +#[test] +fn grpc_err_classifies_sync_functions() { + let events = RecordedEventLevels::default(); + let subscriber = tracing_subscriber::registry().with(events.clone()); + let _guard = tracing::subscriber::set_default(subscriber); + + grpc_err_sync(false).unwrap(); + assert!(!events.contains(tracing::Level::ERROR)); + + grpc_err_sync(true).unwrap_err(); + assert!(events.contains(tracing::Level::ERROR)); +} + +#[tokio::test] +async fn grpc_err_classifies_async_trait_methods() { + let events = RecordedEventLevels::default(); + let subscriber = tracing_subscriber::registry().with(events.clone()); + let _guard = tracing::subscriber::set_default(subscriber); + + AsyncTraitHandler.handle(false).await.unwrap(); + assert!(!events.contains(tracing::Level::ERROR)); + + AsyncTraitHandler.handle(true).await.unwrap_err(); + assert!(events.contains(tracing::Level::ERROR)); +} + #[test] fn ui_tests() { let tests = trybuild::TestCases::new(); @@ -176,4 +280,5 @@ fn ui_tests() { tests.compile_fail("tests/ui/tracing_macros/invalid_skip.rs"); tests.compile_fail("tests/ui/tracing_macros/invalid_skip_all.rs"); tests.compile_fail("tests/ui/tracing_macros/outside_miden_instrument.rs"); + tests.compile_fail("tests/ui/tracing_macros/grpc_err_with_err.rs"); } diff --git a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs new file mode 100644 index 0000000000..f71ae20eaf --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs @@ -0,0 +1,8 @@ +use miden_node_utils::tracing::miden_instrument; + +#[miden_instrument(target = "test", name = "both_directives", err, grpc_err)] +async fn both_directives() -> Result<(), std::io::Error> { + Ok(()) +} + +fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr new file mode 100644 index 0000000000..ea6c5edb84 --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr @@ -0,0 +1,5 @@ +error: `err` cannot be combined with `grpc_err` + --> tests/ui/tracing_macros/grpc_err_with_err.rs:3:63 + | +3 | #[miden_instrument(target = "test", name = "both_directives", err, grpc_err)] + | ^^^ From 97fc563304d0cd6dff7be809292338843f556836 Mon Sep 17 00:00:00 2001 From: sergerad Date: Mon, 24 Aug 2026 17:47:37 +1200 Subject: [PATCH 2/3] Rework grpc_err to err(fault_only) --- .../src/server/get_network_note_status.rs | 2 +- bin/remote-prover/src/server/prove.rs | 2 +- bin/remote-prover/src/server/prover.rs | 4 +- bin/remote-prover/src/server/service.rs | 2 +- .../validator_service/block_subscription.rs | 2 +- .../get_transaction_encryption_key.rs | 2 +- .../submit_proven_transaction.rs | 2 +- crates/block-producer/src/server/mod.rs | 8 +- crates/rpc/src/server/api/get_account.rs | 2 +- .../rpc/src/server/api/get_block_by_number.rs | 2 +- .../server/api/get_block_header_by_number.rs | 2 +- crates/rpc/src/server/api/get_limits.rs | 2 +- .../src/server/api/get_network_note_status.rs | 2 +- .../src/server/api/get_note_script_by_root.rs | 2 +- crates/rpc/src/server/api/get_notes_by_id.rs | 2 +- .../api/get_transaction_encryption_key.rs | 2 +- crates/rpc/src/server/api/status.rs | 2 +- crates/rpc/src/server/api/submit_proven_tx.rs | 2 +- .../src/server/api/submit_proven_tx_batch.rs | 2 +- .../rpc/src/server/api/subscription/block.rs | 2 +- .../rpc/src/server/api/subscription/proof.rs | 2 +- .../server/api/sync_account_storage_maps.rs | 2 +- .../rpc/src/server/api/sync_account_vault.rs | 2 +- crates/rpc/src/server/api/sync_chain_mmr.rs | 2 +- crates/rpc/src/server/api/sync_notes.rs | 2 +- crates/rpc/src/server/api/sync_nullifiers.rs | 2 +- .../rpc/src/server/api/sync_transactions.rs | 2 +- crates/tracing-macro/src/lib.rs | 214 ++++++++++++++---- crates/utils/src/tracing/grpc.rs | 22 +- crates/utils/src/tracing/mod.rs | 2 +- crates/utils/tests/tracing_macros.rs | 77 +++++-- .../tests/ui/tracing_macros/err_duplicate.rs | 8 + .../ui/tracing_macros/err_duplicate.stderr | 11 + .../err_fault_only_invalid_level.rs | 8 + .../err_fault_only_invalid_level.stderr | 5 + .../err_fault_only_unknown_option.rs | 8 + .../err_fault_only_unknown_option.stderr | 5 + .../ui/tracing_macros/err_unknown_mode.rs | 8 + .../ui/tracing_macros/err_unknown_mode.stderr | 5 + .../ui/tracing_macros/grpc_err_with_err.rs | 8 - .../tracing_macros/grpc_err_with_err.stderr | 5 - 41 files changed, 335 insertions(+), 113 deletions(-) create mode 100644 crates/utils/tests/ui/tracing_macros/err_duplicate.rs create mode 100644 crates/utils/tests/ui/tracing_macros/err_duplicate.stderr create mode 100644 crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.rs create mode 100644 crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.stderr create mode 100644 crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.rs create mode 100644 crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.stderr create mode 100644 crates/utils/tests/ui/tracing_macros/err_unknown_mode.rs create mode 100644 crates/utils/tests/ui/tracing_macros/err_unknown_mode.stderr delete mode 100644 crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs delete mode 100644 crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr diff --git a/bin/ntx-builder/src/server/get_network_note_status.rs b/bin/ntx-builder/src/server/get_network_note_status.rs index 4a4137da5b..48a10c9f78 100644 --- a/bin/ntx-builder/src/server/get_network_note_status.rs +++ b/bin/ntx-builder/src/server/get_network_note_status.rs @@ -26,7 +26,7 @@ impl grpc::server::ntx_builder_api::GetNetworkNoteStatus for NtxBuilderRpcServer fields ( note.id = %note_id, ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/bin/remote-prover/src/server/prove.rs b/bin/remote-prover/src/server/prove.rs index 94e3814072..81cd58b6e8 100644 --- a/bin/remote-prover/src/server/prove.rs +++ b/bin/remote-prover/src/server/prove.rs @@ -15,7 +15,7 @@ impl grpc::server::remote_prover_api::Prove for ProverService { #[miden_instrument( target = COMPONENT, name = "remote_prover.prove", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/bin/remote-prover/src/server/prover.rs b/bin/remote-prover/src/server/prover.rs index b61db94ff7..17fdca0498 100644 --- a/bin/remote-prover/src/server/prover.rs +++ b/bin/remote-prover/src/server/prover.rs @@ -71,7 +71,7 @@ trait ProveRequest: Send + Sync { #[miden_instrument( target=COMPONENT, name="prove", - grpc_err, + err(fault_only), )] fn prove_request(&self, request: proto::ProofRequest) -> Result { let input = Self::decode_request(request)?; @@ -80,7 +80,7 @@ trait ProveRequest: Send + Sync { #[miden_instrument( target=COMPONENT, - grpc_err, + err(fault_only), )] fn decode_request(request: proto::ProofRequest) -> Result { use miden_protocol::utils::serde::Deserializable; diff --git a/bin/remote-prover/src/server/service.rs b/bin/remote-prover/src/server/service.rs index ee81d4db19..2a832a62f8 100644 --- a/bin/remote-prover/src/server/service.rs +++ b/bin/remote-prover/src/server/service.rs @@ -27,7 +27,7 @@ impl ProverService { #[miden_instrument( target=COMPONENT, - grpc_err, + err(fault_only), )] pub(super) fn acquire_permit(&self) -> Result { Arc::clone(&self.permits) diff --git a/bin/validator/src/server/validator_service/block_subscription.rs b/bin/validator/src/server/validator_service/block_subscription.rs index 70fc4719b3..94723456af 100644 --- a/bin/validator/src/server/validator_service/block_subscription.rs +++ b/bin/validator/src/server/validator_service/block_subscription.rs @@ -48,7 +48,7 @@ impl grpc::server::validator_api::BlockSubscription for ValidatorService { #[miden_instrument( target = COMPONENT, name = "validator.block_subscription", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs b/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs index 366508647b..ce9d69592c 100644 --- a/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs +++ b/bin/validator/src/server/validator_service/get_transaction_encryption_key.rs @@ -21,7 +21,7 @@ impl grpc::server::validator_api::GetTransactionEncryptionKey for ValidatorServi #[miden_instrument( target = COMPONENT, name = "get_transaction_encryption_key", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/bin/validator/src/server/validator_service/submit_proven_transaction.rs b/bin/validator/src/server/validator_service/submit_proven_transaction.rs index e1cc7e6e9d..f7ff5f8922 100644 --- a/bin/validator/src/server/validator_service/submit_proven_transaction.rs +++ b/bin/validator/src/server/validator_service/submit_proven_transaction.rs @@ -23,7 +23,7 @@ impl grpc::server::validator_api::SubmitProvenTransaction for ValidatorService { #[miden_instrument( target = COMPONENT, name = "submit_proven_transaction", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/block-producer/src/server/mod.rs b/crates/block-producer/src/server/mod.rs index fee2772641..a790409f64 100644 --- a/crates/block-producer/src/server/mod.rs +++ b/crates/block-producer/src/server/mod.rs @@ -311,7 +311,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_proven_tx", - grpc_err, + err(fault_only), )] pub async fn submit_proven_tx( &self, @@ -344,7 +344,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_authenticated_tx", - grpc_err, + err(fault_only), )] #[expect(clippy::let_and_return, reason = "required to lengthen arc lifetime")] pub async fn submit_authenticated_tx( @@ -363,7 +363,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_proven_tx_batch", - grpc_err, + err(fault_only), )] pub async fn submit_proven_tx_batch( &self, @@ -395,7 +395,7 @@ impl BlockProducerApi { #[miden_instrument( target = COMPONENT, name = "block_producer.api.submit_authenticated_tx_batch", - grpc_err, + err(fault_only), )] #[expect(clippy::let_and_return)] pub async fn submit_authenticated_tx_batch( diff --git a/crates/rpc/src/server/api/get_account.rs b/crates/rpc/src/server/api/get_account.rs index 879fbd99f1..8f1418053a 100644 --- a/crates/rpc/src/server/api/get_account.rs +++ b/crates/rpc/src/server/api/get_account.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::GetAccount for RpcService { #[miden_instrument( target = COMPONENT, name = "get_account", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_block_by_number.rs b/crates/rpc/src/server/api/get_block_by_number.rs index 36bf267db6..18ff496e32 100644 --- a/crates/rpc/src/server/api/get_block_by_number.rs +++ b/crates/rpc/src/server/api/get_block_by_number.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::GetBlockByNumber for RpcService { fields( block.number = %request.block_num, ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_block_header_by_number.rs b/crates/rpc/src/server/api/get_block_header_by_number.rs index 26fdf880fd..966fdb385e 100644 --- a/crates/rpc/src/server/api/get_block_header_by_number.rs +++ b/crates/rpc/src/server/api/get_block_header_by_number.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::GetBlockHeaderByNumber for RpcService { fields( block.number = %request.block_num(), ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_limits.rs b/crates/rpc/src/server/api/get_limits.rs index a67e515017..65d9c1b635 100644 --- a/crates/rpc/src/server/api/get_limits.rs +++ b/crates/rpc/src/server/api/get_limits.rs @@ -21,7 +21,7 @@ impl proto::server::rpc_api::GetLimits for RpcService { #[miden_instrument( target = COMPONENT, name = "get_limits", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_network_note_status.rs b/crates/rpc/src/server/api/get_network_note_status.rs index 852646249e..9d813273fb 100644 --- a/crates/rpc/src/server/api/get_network_note_status.rs +++ b/crates/rpc/src/server/api/get_network_note_status.rs @@ -29,7 +29,7 @@ impl proto::server::rpc_api::GetNetworkNoteStatus for RpcService { #[miden_instrument( target = COMPONENT, name = "get_network_note_status", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_note_script_by_root.rs b/crates/rpc/src/server/api/get_note_script_by_root.rs index 01061d96e3..2a103d4999 100644 --- a/crates/rpc/src/server/api/get_note_script_by_root.rs +++ b/crates/rpc/src/server/api/get_note_script_by_root.rs @@ -24,7 +24,7 @@ impl proto::server::rpc_api::GetNoteScriptByRoot for RpcService { #[miden_instrument( target = COMPONENT, name = "get_note_script_by_root", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_notes_by_id.rs b/crates/rpc/src/server/api/get_notes_by_id.rs index 8906e7e0bb..d006d06862 100644 --- a/crates/rpc/src/server/api/get_notes_by_id.rs +++ b/crates/rpc/src/server/api/get_notes_by_id.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::GetNotesById for RpcService { #[miden_instrument( target = COMPONENT, name = "get_notes_by_id", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/get_transaction_encryption_key.rs b/crates/rpc/src/server/api/get_transaction_encryption_key.rs index bb7e4a9f63..97ab611795 100644 --- a/crates/rpc/src/server/api/get_transaction_encryption_key.rs +++ b/crates/rpc/src/server/api/get_transaction_encryption_key.rs @@ -21,7 +21,7 @@ impl proto::server::rpc_api::GetTransactionEncryptionKey for RpcService { #[miden_instrument( target = COMPONENT, name = "get_transaction_encryption_key", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/status.rs b/crates/rpc/src/server/api/status.rs index 7de32a9a21..9edd1c2759 100644 --- a/crates/rpc/src/server/api/status.rs +++ b/crates/rpc/src/server/api/status.rs @@ -22,7 +22,7 @@ impl proto::server::rpc_api::Status for RpcService { #[miden_instrument( target = COMPONENT, name = "status", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/submit_proven_tx.rs b/crates/rpc/src/server/api/submit_proven_tx.rs index 7e5163e4c8..58ed02816a 100644 --- a/crates/rpc/src/server/api/submit_proven_tx.rs +++ b/crates/rpc/src/server/api/submit_proven_tx.rs @@ -36,7 +36,7 @@ impl proto::server::rpc_api::SubmitProvenTx for RpcService { #[miden_instrument( target = COMPONENT, name = "submit_proven_tx", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/submit_proven_tx_batch.rs b/crates/rpc/src/server/api/submit_proven_tx_batch.rs index af55ae15a6..d37182d935 100644 --- a/crates/rpc/src/server/api/submit_proven_tx_batch.rs +++ b/crates/rpc/src/server/api/submit_proven_tx_batch.rs @@ -29,7 +29,7 @@ impl proto::server::rpc_api::SubmitProvenTxBatch for RpcService { #[miden_instrument( target = COMPONENT, name = "submit_proven_tx_batch", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/subscription/block.rs b/crates/rpc/src/server/api/subscription/block.rs index 32f24fdb2a..672a032a87 100644 --- a/crates/rpc/src/server/api/subscription/block.rs +++ b/crates/rpc/src/server/api/subscription/block.rs @@ -31,7 +31,7 @@ impl proto::server::rpc_api::BlockSubscription for RpcService { fields( block.from = %input, ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/subscription/proof.rs b/crates/rpc/src/server/api/subscription/proof.rs index b01f7e9d6a..8c9e9f8cde 100644 --- a/crates/rpc/src/server/api/subscription/proof.rs +++ b/crates/rpc/src/server/api/subscription/proof.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::ProofSubscription for RpcService { fields( block.from = %input, ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_account_storage_maps.rs b/crates/rpc/src/server/api/sync_account_storage_maps.rs index 25f359ffc1..03a10b75d7 100644 --- a/crates/rpc/src/server/api/sync_account_storage_maps.rs +++ b/crates/rpc/src/server/api/sync_account_storage_maps.rs @@ -27,7 +27,7 @@ impl proto::server::rpc_api::SyncAccountStorageMaps for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_account_storage_maps", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_account_vault.rs b/crates/rpc/src/server/api/sync_account_vault.rs index 3be6bb7449..0ac2157795 100644 --- a/crates/rpc/src/server/api/sync_account_vault.rs +++ b/crates/rpc/src/server/api/sync_account_vault.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::SyncAccountVault for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_account_vault", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_chain_mmr.rs b/crates/rpc/src/server/api/sync_chain_mmr.rs index 04e89a2131..e002044bb6 100644 --- a/crates/rpc/src/server/api/sync_chain_mmr.rs +++ b/crates/rpc/src/server/api/sync_chain_mmr.rs @@ -28,7 +28,7 @@ impl proto::server::rpc_api::SyncChainMmr for RpcService { current_client_block_height = %request.current_client_block_height, finality_level = %request.finality_level().as_str_name(), ), - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_notes.rs b/crates/rpc/src/server/api/sync_notes.rs index 2617d69d7b..190b98c2b4 100644 --- a/crates/rpc/src/server/api/sync_notes.rs +++ b/crates/rpc/src/server/api/sync_notes.rs @@ -25,7 +25,7 @@ impl proto::server::rpc_api::SyncNotes for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_notes", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_nullifiers.rs b/crates/rpc/src/server/api/sync_nullifiers.rs index b4c688fb3c..c972ee4db2 100644 --- a/crates/rpc/src/server/api/sync_nullifiers.rs +++ b/crates/rpc/src/server/api/sync_nullifiers.rs @@ -30,7 +30,7 @@ impl proto::server::rpc_api::SyncNullifiers for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_nullifiers", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/rpc/src/server/api/sync_transactions.rs b/crates/rpc/src/server/api/sync_transactions.rs index 348c72b0f9..7cfd0595cf 100644 --- a/crates/rpc/src/server/api/sync_transactions.rs +++ b/crates/rpc/src/server/api/sync_transactions.rs @@ -32,7 +32,7 @@ impl proto::server::rpc_api::SyncTransactions for RpcService { #[miden_instrument( target = COMPONENT, name = "sync_transactions", - grpc_err, + err(fault_only), )] async fn handle( &self, diff --git a/crates/tracing-macro/src/lib.rs b/crates/tracing-macro/src/lib.rs index 7b102cd542..d7b79aaf3a 100644 --- a/crates/tracing-macro/src/lib.rs +++ b/crates/tracing-macro/src/lib.rs @@ -106,12 +106,12 @@ pub fn miden_instrument(attr: TokenStream, item: TokenStream) -> TokenStream { let attr = TokenStream2::from(attr); let mut function = parse_macro_input!(item as ItemFn); let fields = collect_recorded_fields(&function); - let (args, grpc_err) = match merge_inferred_fields(attr, &fields) { + let (args, fault_level) = match merge_inferred_fields(attr, &fields) { Ok(args) => args, Err(error) => return error.into_compile_error().into(), }; - if grpc_err { - apply_grpc_err(&mut function); + if let Some(level) = fault_level { + apply_fault_only_err(&mut function, &level); } let statements = &function.block.stmts; let block: Block = parse_quote! {{ @@ -132,19 +132,22 @@ pub fn miden_instrument(attr: TokenStream, item: TokenStream) -> TokenStream { expanded.into() } -fn merge_inferred_fields(attr: TokenStream2, fields: &[FieldPath]) -> Result<(TokenStream2, bool)> { +fn merge_inferred_fields( + attr: TokenStream2, + fields: &[FieldPath], +) -> Result<(TokenStream2, Option)> { validate_explicit_fields(&attr)?; let mut args = split_top_level_args(attr); reject_skip_directives(&args)?; - let grpc_err = extract_grpc_err_directive(&mut args)?; + let fault_level = extract_err_directive(&mut args)?; // Function arguments often contain large or sensitive values. Always skip them so spans only // contain fields explicitly declared by the caller or inferred from `miden_span_record!`. args.push(quote! { skip_all }); if fields.is_empty() { - return Ok((quote! { #(#args),* }, grpc_err)); + return Ok((quote! { #(#args),* }, fault_level)); } let inferred_fields = quote! { #(#fields = ::tracing::field::Empty),* }; @@ -172,38 +175,39 @@ fn merge_inferred_fields(attr: TokenStream2, fields: &[FieldPath]) -> Result<(To .collect::>(); if merged_existing_fields { - Ok((quote! { #(#args),* }, grpc_err)) + Ok((quote! { #(#args),* }, fault_level)) } else { - Ok((quote! { #(#args,)* fields(#inferred_fields) }, grpc_err)) + Ok((quote! { #(#args,)* fields(#inferred_fields) }, fault_level)) } } /// Rewrites the function body so a returned `Err` is classified via -/// `miden_node_utils::tracing::record_grpc_error` from inside the instrumented span: node faults -/// mark the span with `OTel` error status (like `err` would), while client-caused failures do not — +/// `miden_node_utils::tracing::record_classified_error` from inside the instrumented span: node +/// faults are logged at `level` (`ERROR` unless overridden) and mark the span with `OTel` error +/// status (like `err` would), while client-caused failures are logged at debug level and do not — /// rejecting a bad request is the node behaving correctly, not an application error. /// /// `#[async_trait]` methods are expanded before this macro runs, leaving a non-async fn whose /// body is `Box::pin(async move { ... })`; the classification is applied inside that async block /// so it runs within the instrumented span. -fn apply_grpc_err(function: &mut ItemFn) { - fn classified(body: &TokenStream2) -> Block { +fn apply_fault_only_err(function: &mut ItemFn, level: &TokenStream2) { + fn classified(body: &TokenStream2, level: &TokenStream2) -> Block { parse_quote! {{ #[allow(clippy::redundant_async_block, clippy::redundant_closure_call)] let __miden_instrument_result = #body; if let Err(err) = &__miden_instrument_result { - ::miden_node_utils::tracing::record_grpc_error(err); + ::miden_node_utils::tracing::record_classified_error(err, #level); } __miden_instrument_result }} } - fn wrap_async(statements: &[Stmt]) -> Block { - classified("e! { async move { #(#statements)* }.await }) + fn wrap_async(statements: &[Stmt], level: &TokenStream2) -> Block { + classified("e! { async move { #(#statements)* }.await }, level) } if function.sig.asyncness.is_some() { - let wrapped = wrap_async(&function.block.stmts); + let wrapped = wrap_async(&function.block.stmts, level); *function.block = wrapped; return; } @@ -212,49 +216,173 @@ fn apply_grpc_err(function: &mut ItemFn) { && call.args.len() == 1 && let Some(Expr::Async(async_block)) = call.args.first_mut() { - let wrapped = wrap_async(&async_block.block.stmts); + let wrapped = wrap_async(&async_block.block.stmts, level); async_block.block = wrapped; return; } let statements = &function.block.stmts; - let wrapped = classified("e! { (move || { #(#statements)* })() }); + let wrapped = classified("e! { (move || { #(#statements)* })() }, level); *function.block = wrapped; } -/// Removes the `grpc_err` directive from the argument list, returning whether it was present. +/// Handles the `err` directive, extracting `fault_only` mode when present. /// -/// `grpc_err` is a `miden_instrument` extension, not a `tracing::instrument` argument, so it must -/// not be forwarded. It replaces `err`: combining the two would double-report the error. -fn extract_grpc_err_directive(args: &mut Vec) -> Result { - let is_bare_ident = |arg: &TokenStream2, name: &str| { - let mut tokens = arg.clone().into_iter(); - matches!(tokens.next(), Some(TokenTree::Ident(ident)) if ident == name) - && tokens.next().is_none() - }; +/// `fault_only` is a `miden_instrument` extension to `tracing::instrument`'s `err` directive: the +/// returned `Err` is classified instead of unconditionally reported, so only node faults mark the +/// span as failed. An optional `level = "..."` tunes the level of the fault-side event (`ERROR` by +/// default); client-caused failures are always logged at debug level regardless. +/// +/// Since `tracing::instrument` would reject `fault_only`, the whole `err(...)` argument is removed +/// from the forwarded list and this returns the level tokens (e.g. `::tracing::Level::WARN`) to +/// emit fault events at. Plain `err` and tracing's own modes are forwarded untouched, but their +/// option idents are validated here so a typo like `err(faultonly)` fails with a targeted message +/// rather than a tracing error pointing at expanded code. +fn extract_err_directive(args: &mut Vec) -> Result> { + let mut fault_level = None; + let mut seen_err: Option = None; + let mut retained = Vec::with_capacity(args.len()); + + for arg in args.drain(..) { + let Some(directive) = err_directive_options(&arg) else { + retained.push(arg); + continue; + }; + if let Some(previous) = &seen_err { + let mut error = + syn::Error::new_spanned(&arg, "duplicate `err` directive; only one is allowed"); + error.combine(syn::Error::new_spanned(previous, "first `err` directive here")); + return Err(error); + } + seen_err = Some(arg.clone()); + + match directive { + // Bare `err`: tracing's unconditional error reporting, forwarded as-is. + ErrDirective::Bare => retained.push(arg), + ErrDirective::Options(options) => { + if options.iter().any(|option| is_bare_ident(option, "fault_only")) { + fault_level = Some(parse_fault_only_options(&options)?); + } else { + validate_forwarded_err_options(&options)?; + retained.push(arg); + } + }, + } + } - let mut grpc_err = false; - args.retain(|arg| { - let found = is_bare_ident(arg, "grpc_err"); - grpc_err |= found; - !found - }); + *args = retained; + Ok(fault_level) +} + +/// An `err` directive argument: bare `err` or `err(...)` with its comma-separated options. +enum ErrDirective { + Bare, + Options(Vec), +} + +/// Parses the argument as an `err` directive, returning `None` if it is some other argument. +fn err_directive_options(arg: &TokenStream2) -> Option { + let mut tokens = arg.clone().into_iter(); + match tokens.next() { + Some(TokenTree::Ident(ident)) if ident == "err" => {}, + _ => return None, + } + + match tokens.next() { + None => Some(ErrDirective::Bare), + Some(TokenTree::Group(group)) + if group.delimiter() == Delimiter::Parenthesis && tokens.next().is_none() => + { + Some(ErrDirective::Options(split_top_level_args(group.stream()))) + }, + _ => None, + } +} + +fn is_bare_ident(arg: &TokenStream2, name: &str) -> bool { + let mut tokens = arg.clone().into_iter(); + matches!(tokens.next(), Some(TokenTree::Ident(ident)) if ident == name) + && tokens.next().is_none() +} - if grpc_err { - for arg in args.iter() { - let Some(TokenTree::Ident(ident)) = arg.clone().into_iter().next() else { - continue; - }; - if ident == "err" { +/// Parses the options of an `err(fault_only, ...)` directive into the fault event's level tokens. +fn parse_fault_only_options(options: &[TokenStream2]) -> Result { + let mut level = quote! { ::tracing::Level::ERROR }; + + for option in options { + if is_bare_ident(option, "fault_only") { + continue; + } + + let name_value: syn::MetaNameValue = syn::parse2(option.clone()).map_err(|_| { + syn::Error::new_spanned( + option, + "unsupported `err(fault_only)` option; only `level = \"...\"` can be combined \ + with `fault_only`", + ) + })?; + if !name_value.path.is_ident("level") { + return Err(syn::Error::new_spanned( + option, + "unsupported `err(fault_only)` option; only `level = \"...\"` can be combined \ + with `fault_only`", + )); + } + + let syn::Expr::Lit(syn::ExprLit { lit: syn::Lit::Str(value), .. }) = &name_value.value + else { + return Err(syn::Error::new_spanned( + &name_value.value, + "`level` must be a string literal: one of \"trace\", \"debug\", \"info\", \ + \"warn\" or \"error\"", + )); + }; + level = match value.value().to_ascii_lowercase().as_str() { + "trace" => quote! { ::tracing::Level::TRACE }, + "debug" => quote! { ::tracing::Level::DEBUG }, + "info" => quote! { ::tracing::Level::INFO }, + "warn" => quote! { ::tracing::Level::WARN }, + "error" => quote! { ::tracing::Level::ERROR }, + unknown => { return Err(syn::Error::new_spanned( - arg, - "`err` cannot be combined with `grpc_err`", + value, + format!( + "unknown level \"{unknown}\"; expected one of \"trace\", \"debug\", \ + \"info\", \"warn\" or \"error\"" + ), )); - } + }, + }; + } + + Ok(level) +} + +/// Validates the options of an `err(...)` directive that is forwarded to `tracing::instrument`. +/// +/// Forwarded options are parsed by `tracing::instrument` itself; this only rejects idents outside +/// its `err` grammar (`Debug`, `Display`, `level = ...`) so near-misses of `fault_only` fail here +/// with a message that mentions it. +fn validate_forwarded_err_options(options: &[TokenStream2]) -> Result<()> { + for option in options { + let mut tokens = option.clone().into_iter(); + let first = tokens.next(); + let is_mode = matches!( + &first, + Some(TokenTree::Ident(ident)) if ident == "Debug" || ident == "Display" + ) && tokens.next().is_none(); + let is_level = matches!(&first, Some(TokenTree::Ident(ident)) if ident == "level"); + + if !is_mode && !is_level { + return Err(syn::Error::new_spanned( + option, + "unsupported `err` option; expected `fault_only`, `Debug`, `Display` or `level = \ + \"...\"`", + )); } } - Ok(grpc_err) + Ok(()) } fn reject_skip_directives(args: &[TokenStream2]) -> Result<()> { diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index 2e36d5c0e7..4e8e03f3a0 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -163,18 +163,26 @@ impl GrpcFault for tonic::Status { /// Records a request-handling error on the current span. /// -/// Called by `miden_instrument`'s `grpc_err` directive. Node faults are logged at error level and -/// mark the span with `OTel` error status, matching the plain `err` directive; client-caused -/// failures are logged at debug level and leave the span status untouched, since rejecting a bad -/// request is the node behaving correctly. -pub fn record_grpc_error(err: &E) +/// Called by `miden_instrument`'s `err(fault_only)` directive. Node faults are logged at +/// `fault_level` (`ERROR` unless the directive says `level = "..."`) and mark the span with `OTel` +/// error status regardless of that level — the level tunes event verbosity, while span status +/// always follows the fault classification. Client-caused failures are logged at debug level and +/// leave the span status untouched, since rejecting a bad request is the node behaving correctly. +pub fn record_classified_error(err: &E, fault_level: tracing::Level) where E: GrpcFault + std::error::Error, { use crate::ErrorReport; if err.is_server_fault() { - tracing::error!(error = err.as_report()); + // `tracing::event!` requires a const level, so dispatch to the per-level macros. + match fault_level { + tracing::Level::ERROR => tracing::error!(error = err.as_report()), + tracing::Level::WARN => tracing::warn!(error = err.as_report()), + tracing::Level::INFO => tracing::info!(error = err.as_report()), + tracing::Level::DEBUG => tracing::debug!(error = err.as_report()), + tracing::Level::TRACE => tracing::trace!(error = err.as_report()), + } tracing::Span::current().set_error(err); } else { tracing::debug!(error = err.as_report()); @@ -370,7 +378,7 @@ mod tests { /// The trace layer's classifier decides which responses mark the request span as an error; it /// must agree with [`is_server_fault_code`], which drives the same decision for handler spans - /// via `grpc_err`. + /// via `err(fault_only)`. #[test] fn classifier_agrees_with_fault_classification() { // 0..=16 covers every gRPC status code. diff --git a/crates/utils/src/tracing/mod.rs b/crates/utils/src/tracing/mod.rs index e6e5880e54..002f409eb2 100644 --- a/crates/utils/src/tracing/mod.rs +++ b/crates/utils/src/tracing/mod.rs @@ -1,6 +1,6 @@ pub mod grpc; mod span_ext; -pub use grpc::{GrpcFault, is_server_fault_code, record_grpc_error}; +pub use grpc::{GrpcFault, is_server_fault_code, record_classified_error}; pub use miden_node_tracing_macro::{miden_instrument, miden_span_record}; pub use span_ext::ErrorSpanExt; diff --git a/crates/utils/tests/tracing_macros.rs b/crates/utils/tests/tracing_macros.rs index 6888ed0901..5004e0b06c 100644 --- a/crates/utils/tests/tracing_macros.rs +++ b/crates/utils/tests/tracing_macros.rs @@ -186,26 +186,47 @@ fn multiple_span_record_macros_can_record_fields_after_span_creation() { assert_eq!(recorded.get("transaction.id").as_deref(), Some("multi-call-tx")); } -#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_client_fault", grpc_err)] -async fn grpc_err_client_fault() -> Result<(), tonic::Status> { +#[miden_instrument( + target = "miden-node-utils-test", + name = "fault_only_client_fault", + err(fault_only) +)] +async fn fault_only_client_fault() -> Result<(), tonic::Status> { Err(tonic::Status::invalid_argument("bad request")) } -#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_server_fault", grpc_err)] -async fn grpc_err_server_fault() -> Result<(), tonic::Status> { +#[miden_instrument( + target = "miden-node-utils-test", + name = "fault_only_server_fault", + err(fault_only) +)] +async fn fault_only_server_fault() -> Result<(), tonic::Status> { Err(tonic::Status::internal("node fault")) } +#[miden_instrument( + target = "miden-node-utils-test", + name = "fault_only_warn_level", + err(fault_only, level = "warn") +)] +async fn fault_only_warn_level(fail_with: tonic::Status) -> Result<(), tonic::Status> { + Err(fail_with) +} + #[tonic::async_trait] -trait GrpcErrHandler { +trait FaultOnlyErrHandler { async fn handle(&self, fail: bool) -> Result<(), tonic::Status>; } struct AsyncTraitHandler; #[tonic::async_trait] -impl GrpcErrHandler for AsyncTraitHandler { - #[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_async_trait", grpc_err)] +impl FaultOnlyErrHandler for AsyncTraitHandler { + #[miden_instrument( + target = "miden-node-utils-test", + name = "fault_only_async_trait", + err(fault_only) + )] async fn handle(&self, fail: bool) -> Result<(), tonic::Status> { if fail { return Err(tonic::Status::internal("node fault")); @@ -215,30 +236,47 @@ impl GrpcErrHandler for AsyncTraitHandler { } #[tokio::test] -async fn grpc_err_client_faults_are_not_error_events() { +async fn fault_only_client_faults_are_not_error_events() { let events = RecordedEventLevels::default(); let subscriber = tracing_subscriber::registry().with(events.clone()); let _guard = tracing::subscriber::set_default(subscriber); - grpc_err_client_fault().await.unwrap_err(); + fault_only_client_fault().await.unwrap_err(); assert!(events.contains(tracing::Level::DEBUG)); assert!(!events.contains(tracing::Level::ERROR)); } #[tokio::test] -async fn grpc_err_server_faults_are_error_events() { +async fn fault_only_server_faults_are_error_events() { let events = RecordedEventLevels::default(); let subscriber = tracing_subscriber::registry().with(events.clone()); let _guard = tracing::subscriber::set_default(subscriber); - grpc_err_server_fault().await.unwrap_err(); + fault_only_server_fault().await.unwrap_err(); assert!(events.contains(tracing::Level::ERROR)); } -#[miden_instrument(target = "miden-node-utils-test", name = "grpc_err_sync", grpc_err)] -fn grpc_err_sync(fail: bool) -> Result<(), tonic::Status> { +#[tokio::test] +async fn fault_only_level_applies_to_server_faults_only() { + let events = RecordedEventLevels::default(); + let subscriber = tracing_subscriber::registry().with(events.clone()); + let _guard = tracing::subscriber::set_default(subscriber); + + fault_only_warn_level(tonic::Status::internal("node fault")).await.unwrap_err(); + assert!(events.contains(tracing::Level::WARN)); + assert!(!events.contains(tracing::Level::ERROR)); + + fault_only_warn_level(tonic::Status::invalid_argument("bad request")) + .await + .unwrap_err(); + assert!(events.contains(tracing::Level::DEBUG)); + assert!(!events.contains(tracing::Level::ERROR)); +} + +#[miden_instrument(target = "miden-node-utils-test", name = "fault_only_sync", err(fault_only))] +fn fault_only_sync(fail: bool) -> Result<(), tonic::Status> { if fail { return Err(tonic::Status::internal("node fault")); } @@ -246,20 +284,20 @@ fn grpc_err_sync(fail: bool) -> Result<(), tonic::Status> { } #[test] -fn grpc_err_classifies_sync_functions() { +fn fault_only_classifies_sync_functions() { let events = RecordedEventLevels::default(); let subscriber = tracing_subscriber::registry().with(events.clone()); let _guard = tracing::subscriber::set_default(subscriber); - grpc_err_sync(false).unwrap(); + fault_only_sync(false).unwrap(); assert!(!events.contains(tracing::Level::ERROR)); - grpc_err_sync(true).unwrap_err(); + fault_only_sync(true).unwrap_err(); assert!(events.contains(tracing::Level::ERROR)); } #[tokio::test] -async fn grpc_err_classifies_async_trait_methods() { +async fn fault_only_classifies_async_trait_methods() { let events = RecordedEventLevels::default(); let subscriber = tracing_subscriber::registry().with(events.clone()); let _guard = tracing::subscriber::set_default(subscriber); @@ -280,5 +318,8 @@ fn ui_tests() { tests.compile_fail("tests/ui/tracing_macros/invalid_skip.rs"); tests.compile_fail("tests/ui/tracing_macros/invalid_skip_all.rs"); tests.compile_fail("tests/ui/tracing_macros/outside_miden_instrument.rs"); - tests.compile_fail("tests/ui/tracing_macros/grpc_err_with_err.rs"); + tests.compile_fail("tests/ui/tracing_macros/err_duplicate.rs"); + tests.compile_fail("tests/ui/tracing_macros/err_fault_only_unknown_option.rs"); + tests.compile_fail("tests/ui/tracing_macros/err_fault_only_invalid_level.rs"); + tests.compile_fail("tests/ui/tracing_macros/err_unknown_mode.rs"); } diff --git a/crates/utils/tests/ui/tracing_macros/err_duplicate.rs b/crates/utils/tests/ui/tracing_macros/err_duplicate.rs new file mode 100644 index 0000000000..bf8a4978d0 --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_duplicate.rs @@ -0,0 +1,8 @@ +use miden_node_utils::tracing::miden_instrument; + +#[miden_instrument(target = "test", name = "duplicate_err", err, err(fault_only))] +async fn duplicate_err() -> Result<(), std::io::Error> { + Ok(()) +} + +fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/err_duplicate.stderr b/crates/utils/tests/ui/tracing_macros/err_duplicate.stderr new file mode 100644 index 0000000000..68976ffdc0 --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_duplicate.stderr @@ -0,0 +1,11 @@ +error: duplicate `err` directive; only one is allowed + --> tests/ui/tracing_macros/err_duplicate.rs:3:66 + | +3 | #[miden_instrument(target = "test", name = "duplicate_err", err, err(fault_only))] + | ^^^^^^^^^^^^^^^ + +error: first `err` directive here + --> tests/ui/tracing_macros/err_duplicate.rs:3:61 + | +3 | #[miden_instrument(target = "test", name = "duplicate_err", err, err(fault_only))] + | ^^^ diff --git a/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.rs b/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.rs new file mode 100644 index 0000000000..9ac3b584c9 --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.rs @@ -0,0 +1,8 @@ +use miden_node_utils::tracing::miden_instrument; + +#[miden_instrument(target = "test", name = "invalid_level", err(fault_only, level = "loud"))] +async fn invalid_level() -> Result<(), std::io::Error> { + Ok(()) +} + +fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.stderr b/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.stderr new file mode 100644 index 0000000000..3390e0086b --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_fault_only_invalid_level.stderr @@ -0,0 +1,5 @@ +error: unknown level "loud"; expected one of "trace", "debug", "info", "warn" or "error" + --> tests/ui/tracing_macros/err_fault_only_invalid_level.rs:3:85 + | +3 | #[miden_instrument(target = "test", name = "invalid_level", err(fault_only, level = "loud"))] + | ^^^^^^ diff --git a/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.rs b/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.rs new file mode 100644 index 0000000000..e7aefc2c6d --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.rs @@ -0,0 +1,8 @@ +use miden_node_utils::tracing::miden_instrument; + +#[miden_instrument(target = "test", name = "unknown_option", err(fault_only, Debug))] +async fn unknown_option() -> Result<(), std::io::Error> { + Ok(()) +} + +fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.stderr b/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.stderr new file mode 100644 index 0000000000..aac75af9ae --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_fault_only_unknown_option.stderr @@ -0,0 +1,5 @@ +error: unsupported `err(fault_only)` option; only `level = "..."` can be combined with `fault_only` + --> tests/ui/tracing_macros/err_fault_only_unknown_option.rs:3:78 + | +3 | #[miden_instrument(target = "test", name = "unknown_option", err(fault_only, Debug))] + | ^^^^^ diff --git a/crates/utils/tests/ui/tracing_macros/err_unknown_mode.rs b/crates/utils/tests/ui/tracing_macros/err_unknown_mode.rs new file mode 100644 index 0000000000..ff60aa5775 --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_unknown_mode.rs @@ -0,0 +1,8 @@ +use miden_node_utils::tracing::miden_instrument; + +#[miden_instrument(target = "test", name = "unknown_mode", err(faultonly))] +async fn unknown_mode() -> Result<(), std::io::Error> { + Ok(()) +} + +fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/err_unknown_mode.stderr b/crates/utils/tests/ui/tracing_macros/err_unknown_mode.stderr new file mode 100644 index 0000000000..6e265fe90f --- /dev/null +++ b/crates/utils/tests/ui/tracing_macros/err_unknown_mode.stderr @@ -0,0 +1,5 @@ +error: unsupported `err` option; expected `fault_only`, `Debug`, `Display` or `level = "..."` + --> tests/ui/tracing_macros/err_unknown_mode.rs:3:64 + | +3 | #[miden_instrument(target = "test", name = "unknown_mode", err(faultonly))] + | ^^^^^^^^^ diff --git a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs deleted file mode 100644 index f71ae20eaf..0000000000 --- a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.rs +++ /dev/null @@ -1,8 +0,0 @@ -use miden_node_utils::tracing::miden_instrument; - -#[miden_instrument(target = "test", name = "both_directives", err, grpc_err)] -async fn both_directives() -> Result<(), std::io::Error> { - Ok(()) -} - -fn main() {} diff --git a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr b/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr deleted file mode 100644 index ea6c5edb84..0000000000 --- a/crates/utils/tests/ui/tracing_macros/grpc_err_with_err.stderr +++ /dev/null @@ -1,5 +0,0 @@ -error: `err` cannot be combined with `grpc_err` - --> tests/ui/tracing_macros/grpc_err_with_err.rs:3:63 - | -3 | #[miden_instrument(target = "test", name = "both_directives", err, grpc_err)] - | ^^^ From 30f0e6a8611d393a40b56e417d7c29c1b6dfcdeb Mon Sep 17 00:00:00 2001 From: sergerad Date: Mon, 24 Aug 2026 17:55:55 +1200 Subject: [PATCH 3/3] Docs --- crates/tracing-macro/src/lib.rs | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/crates/tracing-macro/src/lib.rs b/crates/tracing-macro/src/lib.rs index d7b79aaf3a..562c3d45d7 100644 --- a/crates/tracing-macro/src/lib.rs +++ b/crates/tracing-macro/src/lib.rs @@ -101,6 +101,35 @@ const ALLOWED_FIELD_NAMES: &[&str] = &[ "workers.count", ]; +/// A drop-in replacement for `tracing::instrument` enforcing the node's telemetry conventions. +/// +/// Differences from `tracing::instrument`: +/// +/// - Function arguments are never recorded: `skip_all` is always applied, and explicit `skip` / +/// `skip_all` directives are rejected. Span fields must instead be declared with `fields(...)` +/// or recorded later in the body with `miden_span_record!`; either way the field names are +/// validated against the node's allowed span field names, and recorded fields are inferred and +/// pre-declared as empty on the span. +/// - The `err` directive gains a `fault_only` mode for request handlers: +/// +/// ```ignore +/// #[miden_instrument( +/// target = COMPONENT, +/// name = "block_producer.api.submit_proven_tx", +/// err(fault_only), +/// )] +/// ``` +/// +/// Where plain `err` unconditionally reports a returned `Err`, `err(fault_only)` classifies it +/// via the `GrpcFault` trait (`miden_node_utils::tracing`): node faults are logged at `ERROR` +/// with the full error report and mark the span with `OTel` error status, while client-caused +/// failures are logged at debug level and leave the span status untouched — rejecting a bad +/// request is the node behaving correctly, not an application error. An optional +/// `level = "..."` (`"trace"` through `"error"`) tunes the level of the fault-side event only, +/// e.g. `err(fault_only, level = "warn")`; span error status always follows the classification +/// regardless of level. +/// +/// All other arguments are forwarded to `tracing::instrument` unchanged. #[proc_macro_attribute] pub fn miden_instrument(attr: TokenStream, item: TokenStream) -> TokenStream { let attr = TokenStream2::from(attr);