From 9efc28a8953f7fd1b60fa3677f7b1563e2cb34f0 Mon Sep 17 00:00:00 2001 From: sergerad Date: Sun, 16 Feb 2025 17:07:35 +1300 Subject: [PATCH 01/20] Use tower_http::TraceLayer in block producer --- Cargo.lock | 4 ++++ Cargo.toml | 2 ++ bin/faucet/Cargo.toml | 4 ++-- crates/block-producer/Cargo.toml | 3 +++ crates/block-producer/src/server.rs | 14 ++++++++++++-- crates/utils/Cargo.toml | 1 + crates/utils/src/tracing/grpc.rs | 6 +++--- 7 files changed, 27 insertions(+), 7 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index fe8458343..a2ca83fa5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1876,6 +1876,7 @@ dependencies = [ "assert_matches", "async-trait", "futures", + "http", "itertools 0.14.0", "miden-air", "miden-block-prover", @@ -1895,6 +1896,8 @@ dependencies = [ "tokio", "tokio-stream", "tonic", + "tower 0.5.2", + "tower-http 0.6.2", "tracing", "url", "winterfell", @@ -3704,6 +3707,7 @@ dependencies = [ "http", "http-body", "pin-project-lite", + "tower 0.5.2", "tower-layer", "tower-service", "tracing", diff --git a/Cargo.toml b/Cargo.toml index 7d8563b0e..072c257f8 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -44,6 +44,8 @@ thiserror = { version = "2.0", default-features = false } tokio = { version = "1.40", features = ["rt-multi-thread"] } tokio-stream = { version = "0.1" } tonic = { version = "0.12" } +tower = "0.5" +tower-http = { version = "0.6" } tracing = { version = "0.1" } tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt", "json"] } url = { version = "2.5", features = ["serde"] } diff --git a/bin/faucet/Cargo.toml b/bin/faucet/Cargo.toml index 83194cc0f..a06cf1de3 100644 --- a/bin/faucet/Cargo.toml +++ b/bin/faucet/Cargo.toml @@ -34,8 +34,8 @@ thiserror = { workspace = true } tokio = { workspace = true, features = ["fs"] } toml = { version = "0.8" } tonic = { workspace = true } -tower = "0.5" -tower-http = { version = "0.6", features = ["cors", "set-header", "trace"] } +tower = { workspace = true } +tower-http = { workspace = true, features = ["cors", "set-header", "trace"] } tracing = { workspace = true } url = { workspace = true } diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index 6c354019c..eb85fa5f5 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -20,6 +20,7 @@ tracing-forest = ["miden-node-utils/tracing-forest"] [dependencies] async-trait = { version = "0.1" } futures = { version = "0.3" } +http = { version = "1.2" } itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } @@ -35,6 +36,8 @@ thiserror = { workspace = true } tokio = { workspace = true, features = ["macros", "net", "rt-multi-thread", "sync", "time"] } tokio-stream = { workspace = true, features = ["net"] } tonic = { workspace = true } +tower = { workspace = true } +tower-http = { workspace = true, features = ["util"] } tracing = { workspace = true } url = { workspace = true } diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 251d0b339..2ba26a772 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -1,4 +1,4 @@ -use std::collections::HashMap; +use std::{collections::HashMap, time::Duration}; use miden_node_proto::generated::{ block_producer::api_server, requests::SubmitProvenTransactionRequest, @@ -15,6 +15,7 @@ use miden_objects::{ use tokio::{net::TcpListener, sync::Mutex}; use tokio_stream::wrappers::TcpListenerStream; use tonic::Status; +use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; use tracing::{debug, info, instrument}; use crate::{ @@ -211,8 +212,17 @@ impl BlockProducerRpcServer { } async fn serve(self, listener: TcpListener) -> Result<(), tonic::transport::Error> { + let trace_layer = TraceLayer::new_for_grpc() + .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) + .on_request(|_request: &http::Request<_>, _span: &tracing::Span| todo!()) + .on_response( + |_response: &http::Response<_>, _latency: Duration, _span: &tracing::Span| todo!(), + ) + .on_failure( + |_error: GrpcFailureClass, _latency: Duration, _span: &tracing::Span| todo!(), + ); tonic::transport::Server::builder() - .trace_fn(miden_node_utils::tracing::grpc::block_producer_trace_fn) + .layer(trace_layer) .add_service(api_server::ApiServer::new(self)) .serve_with_incoming(TcpListenerStream::new(listener)) .await diff --git a/crates/utils/Cargo.toml b/crates/utils/Cargo.toml index 73995dca5..f5fe8fb1a 100644 --- a/crates/utils/Cargo.toml +++ b/crates/utils/Cargo.toml @@ -35,6 +35,7 @@ tracing = { workspace = true } tracing-forest = { version = "0.1", optional = true, features = ["chrono"] } tracing-opentelemetry = { version = "0.29" } tracing-subscriber = { workspace = true } + # Optional dependencies enabled by `vergen` feature. # This must match the version expected by `vergen-gitcl`. vergen = { "version" = "9.0", optional = true } diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index 1e951af12..ab343317f 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -6,7 +6,7 @@ use tracing_opentelemetry::OpenTelemetrySpanExt; /// Creates an `info` span following the open-telemetry standard: `block-producer.rpc/{method}`. /// Additionally also pulls in remote tracing context which allows the server trace to be connected /// to the client's origin trace. -pub fn block_producer_trace_fn(request: &http::Request<()>) -> tracing::Span { +pub fn block_producer_trace_fn(request: &http::Request) -> tracing::Span { let span = if let Some("SubmitProvenTransaction") = request.uri().path().rsplit('/').next() { tracing::info_span!("block-producer.rpc/SubmitProvenTransaction") } else { @@ -22,7 +22,7 @@ pub fn block_producer_trace_fn(request: &http::Request<()>) -> tracing::Span { /// Creates an `info` span following the open-telemetry standard: `store.rpc/{method}`. Additionally /// also pulls in remote tracing context which allows the server trace to be connected to the /// client's origin trace. -pub fn store_trace_fn(request: &http::Request<()>) -> tracing::Span { +pub fn store_trace_fn(request: &http::Request) -> tracing::Span { let span = match request.uri().path().rsplit('/').next() { Some("ApplyBlock") => tracing::info_span!("store.rpc/ApplyBlock"), Some("CheckNullifiers") => tracing::info_span!("store.rpc/CheckNullifiers"), @@ -47,7 +47,7 @@ pub fn store_trace_fn(request: &http::Request<()>) -> tracing::Span { /// Adds remote tracing context to the span. /// /// Could be expanded in the future by adding in more open-telemetry properties. -fn add_otel_span_attributes(span: tracing::Span, request: &http::Request<()>) -> tracing::Span { +fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) -> tracing::Span { // Pull the open-telemetry parent context using the HTTP extractor. We could make a more // generic gRPC extractor by utilising the gRPC metadata. However that // (a) requires cloning headers, From 3d1c0735fb9122868129137edbda230f4e4b18f7 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 21 Feb 2025 16:03:17 +1300 Subject: [PATCH 02/20] Add trace feature to root import --- Cargo.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Cargo.toml b/Cargo.toml index 072c257f8..0acf8dd61 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -45,7 +45,7 @@ tokio = { version = "1.40", features = ["rt-multi-thread"] } tokio-stream = { version = "0.1" } tonic = { version = "0.12" } tower = "0.5" -tower-http = { version = "0.6" } +tower-http = { version = "0.6", features = ["trace"] } tracing = { version = "0.1" } tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt", "json"] } url = { version = "2.5", features = ["serde"] } From 3cdfe80f893e8a5b5c9557bcd30e5c1911dd192a Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 21 Feb 2025 19:24:54 +1300 Subject: [PATCH 03/20] Add info! and error! lines --- crates/block-producer/src/server.rs | 19 ++++++++++++++----- 1 file changed, 14 insertions(+), 5 deletions(-) diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 2ba26a772..cd51f8eb4 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -214,13 +214,22 @@ impl BlockProducerRpcServer { async fn serve(self, listener: TcpListener) -> Result<(), tonic::transport::Error> { let trace_layer = TraceLayer::new_for_grpc() .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) - .on_request(|_request: &http::Request<_>, _span: &tracing::Span| todo!()) + .on_request(|request: &http::Request<_>, _span: &tracing::Span| { + tracing::info!( + "request: {} {} {:?}", + request.method(), + request.uri().path(), + request.headers() + ); + }) .on_response( - |_response: &http::Response<_>, _latency: Duration, _span: &tracing::Span| todo!(), + |response: &http::Response<_>, latency: Duration, _span: &tracing::Span| { + tracing::info!("response: {} {:?}", response.status(), latency); + }, ) - .on_failure( - |_error: GrpcFailureClass, _latency: Duration, _span: &tracing::Span| todo!(), - ); + .on_failure(|error: GrpcFailureClass, _latency: Duration, _span: &tracing::Span| { + tracing::error!("error: {}", error); + }); tonic::transport::Server::builder() .layer(trace_layer) .add_service(api_server::ApiServer::new(self)) From 4f4a9361fc886befdb6d7fdbcb06005024b3411c Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 21 Feb 2025 19:25:36 +1300 Subject: [PATCH 04/20] Fix honeycomb URL --- docs/operator.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/docs/operator.md b/docs/operator.md index 286aa64eb..9be133afd 100644 --- a/docs/operator.md +++ b/docs/operator.md @@ -90,6 +90,7 @@ block_builder.build_block ┕━ mempool.revert_expired_transactions ┕━ mempool.revert_transactions ``` + #### Batch building @@ -143,7 +144,7 @@ The exporter can be configured using environment variables as specified in the o > [setup guide](https://docs.honeycomb.io/send-data/opentelemetry/#using-the-honeycomb-opentelemetry-endpoint). ```sh -OTEL_EXPORTER_OTLP_ENDPOINT=api.honeycomb.io:443 \ +OTEL_EXPORTER_OTLP_ENDPOINT=https://api.honeycomb.io:443 \ OTEL_EXPORTER_OTLP_HEADERS="x-honeycomb-team=your-api-key" \ miden-node start --open-telemetry node ``` From 47e9d82f954a97b1c5cf095a22a4b29e1dc92b94 Mon Sep 17 00:00:00 2001 From: sergerad Date: Sat, 22 Feb 2025 10:06:40 +1300 Subject: [PATCH 05/20] Use http trace layer --- crates/block-producer/src/server.rs | 27 ++++++++++++++------------- 1 file changed, 14 insertions(+), 13 deletions(-) diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index cd51f8eb4..5fa181f18 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -15,8 +15,8 @@ use miden_objects::{ use tokio::{net::TcpListener, sync::Mutex}; use tokio_stream::wrappers::TcpListenerStream; use tonic::Status; -use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; -use tracing::{debug, info, instrument}; +use tower_http::{classify::ServerErrorsFailureClass, trace::TraceLayer}; +use tracing::{debug, error, info, instrument, Span}; use crate::{ batch_builder::BatchBuilder, @@ -212,24 +212,25 @@ impl BlockProducerRpcServer { } async fn serve(self, listener: TcpListener) -> Result<(), tonic::transport::Error> { - let trace_layer = TraceLayer::new_for_grpc() + // Configure the trace layer with callbacks. + let trace_layer = TraceLayer::new_for_http() .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) - .on_request(|request: &http::Request<_>, _span: &tracing::Span| { - tracing::info!( - "request: {} {} {:?}", + .on_request(|request: &http::Request<_>, _span: &Span| { + info!( + "request: {} {} {} {:?}", request.method(), + request.uri().host().unwrap_or("unknown_host"), request.uri().path(), request.headers() ); }) - .on_response( - |response: &http::Response<_>, latency: Duration, _span: &tracing::Span| { - tracing::info!("response: {} {:?}", response.status(), latency); - }, - ) - .on_failure(|error: GrpcFailureClass, _latency: Duration, _span: &tracing::Span| { - tracing::error!("error: {}", error); + .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { + info!("response: {} {:?}", response.status(), latency); + }) + .on_failure(|error: ServerErrorsFailureClass, latency: Duration, _span: &Span| { + error!("error: {} {:?}", error, latency); }); + // Build the gRPC server with the API service and trace layer. tonic::transport::Server::builder() .layer(trace_layer) .add_service(api_server::ApiServer::new(self)) From fda2d1c96b04d2c3a0ac8b6b5eca2dba7096016f Mon Sep 17 00:00:00 2001 From: sergerad Date: Sat, 22 Feb 2025 18:16:21 +1300 Subject: [PATCH 06/20] Add trace unit test to mempool --- Cargo.lock | 317 ++++++++++++++++++++- crates/block-producer/Cargo.toml | 2 +- crates/block-producer/src/mempool/tests.rs | 14 + crates/utils/Cargo.toml | 6 +- crates/utils/src/logging.rs | 39 ++- 5 files changed, 366 insertions(+), 12 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index a2ca83fa5..fe0a74449 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -136,6 +136,151 @@ version = "1.5.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9b34d609dfbaf33d6889b2b7106d3ca345eacad44200913df5ba02bfd31d2ba9" +[[package]] +name = "async-channel" +version = "1.9.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "81953c529336010edd6d8e358f886d9581267795c61b19475b71314bffa46d35" +dependencies = [ + "concurrent-queue", + "event-listener 2.5.3", + "futures-core", +] + +[[package]] +name = "async-channel" +version = "2.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "89b47800b0be77592da0afd425cc03468052844aff33b84e33cc696f64e77b6a" +dependencies = [ + "concurrent-queue", + "event-listener-strategy", + "futures-core", + "pin-project-lite", +] + +[[package]] +name = "async-executor" +version = "1.13.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "30ca9a001c1e8ba5149f91a74362376cc6bc5b919d92d988668657bd570bdcec" +dependencies = [ + "async-task", + "concurrent-queue", + "fastrand", + "futures-lite", + "slab", +] + +[[package]] +name = "async-global-executor" +version = "2.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "05b1b633a2115cd122d73b955eadd9916c18c8f510ec9cd1686404c60ad1c29c" +dependencies = [ + "async-channel 2.3.1", + "async-executor", + "async-io", + "async-lock", + "blocking", + "futures-lite", + "once_cell", +] + +[[package]] +name = "async-io" +version = "2.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "43a2b323ccce0a1d90b449fd71f2a06ca7faa7c54c2751f06c9bd851fc061059" +dependencies = [ + "async-lock", + "cfg-if", + "concurrent-queue", + "futures-io", + "futures-lite", + "parking", + "polling", + "rustix", + "slab", + "tracing", + "windows-sys 0.59.0", +] + +[[package]] +name = "async-lock" +version = "3.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ff6e472cdea888a4bd64f342f09b3f50e1886d32afe8df3d663c01140b811b18" +dependencies = [ + "event-listener 5.4.0", + "event-listener-strategy", + "pin-project-lite", +] + +[[package]] +name = "async-process" +version = "2.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "63255f1dc2381611000436537bbedfe83183faa303a5a0edaf191edef06526bb" +dependencies = [ + "async-channel 2.3.1", + "async-io", + "async-lock", + "async-signal", + "async-task", + "blocking", + "cfg-if", + "event-listener 5.4.0", + "futures-lite", + "rustix", + "tracing", +] + +[[package]] +name = "async-signal" +version = "0.2.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "637e00349800c0bdf8bfc21ebbc0b6524abea702b0da4168ac00d070d0c0b9f3" +dependencies = [ + "async-io", + "async-lock", + "atomic-waker", + "cfg-if", + "futures-core", + "futures-io", + "rustix", + "signal-hook-registry", + "slab", + "windows-sys 0.59.0", +] + +[[package]] +name = "async-std" +version = "1.13.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c634475f29802fde2b8f0b505b1bd00dfe4df7d4a000f0b36f7671197d5c3615" +dependencies = [ + "async-channel 1.9.0", + "async-global-executor", + "async-io", + "async-lock", + "async-process", + "crossbeam-utils", + "futures-channel", + "futures-core", + "futures-io", + "futures-lite", + "gloo-timers", + "kv-log-macro", + "log", + "memchr", + "once_cell", + "pin-project-lite", + "pin-utils", + "slab", + "wasm-bindgen-futures", +] + [[package]] name = "async-stream" version = "0.3.6" @@ -158,6 +303,12 @@ dependencies = [ "syn", ] +[[package]] +name = "async-task" +version = "4.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b75356056920673b02621b35afd0f7dda9306d03c79a30f5c56c44cf256e3de" + [[package]] name = "async-trait" version = "0.1.86" @@ -405,6 +556,19 @@ dependencies = [ "generic-array", ] +[[package]] +name = "blocking" +version = "1.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "703f41c54fc768e63e091340b424302bb1c29ef4aa0c7f10fe849dfb114d29ea" +dependencies = [ + "async-channel 2.3.1", + "async-task", + "futures-io", + "futures-lite", + "piper", +] + [[package]] name = "bumpalo" version = "3.17.0" @@ -568,6 +732,15 @@ version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5b63caa9aa9397e2d9480a9b13673856c78d8ac123288526c37d7839f2a86990" +[[package]] +name = "concurrent-queue" +version = "2.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4ca0197aee26d1ae37445ee532fefce43251d24cc7c166799f4d46817f1d3973" +dependencies = [ + "crossbeam-utils", +] + [[package]] name = "constant_time_eq" version = "0.3.1" @@ -840,6 +1013,33 @@ dependencies = [ "windows-sys 0.59.0", ] +[[package]] +name = "event-listener" +version = "2.5.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0206175f82b8d6bf6652ff7d71a1e27fd2e4efde587fd368662814d6ec1d9ce0" + +[[package]] +name = "event-listener" +version = "5.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3492acde4c3fc54c845eaab3eed8bd00c7a7d881f78bfc801e43a93dec1331ae" +dependencies = [ + "concurrent-queue", + "parking", + "pin-project-lite", +] + +[[package]] +name = "event-listener-strategy" +version = "0.5.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3c3e4e0dd3673c1139bf041f3008816d9cf2946bbfac2945c09e523b8d7b05b2" +dependencies = [ + "event-listener 5.4.0", + "pin-project-lite", +] + [[package]] name = "fallible-iterator" version = "0.3.0" @@ -949,6 +1149,19 @@ version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9e5c1b78ca4aae1ac06c48a526a655760685149f0d465d21f37abfe57ce075c6" +[[package]] +name = "futures-lite" +version = "2.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cef40d21ae2c515b51041df9ed313ed21e572df340ea58a922a0aefe7e8891a1" +dependencies = [ + "fastrand", + "futures-core", + "futures-io", + "parking", + "pin-project-lite", +] + [[package]] name = "futures-macro" version = "0.3.31" @@ -1050,6 +1263,18 @@ version = "0.3.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a8d1add55171497b4705a648c6b583acafb01d58050a51727785f0b2c8e0a2b2" +[[package]] +name = "gloo-timers" +version = "0.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbb143cf96099802033e0d4f4963b19fd2e0b728bcf076cd9cf7f6634f092994" +dependencies = [ + "futures-channel", + "futures-core", + "js-sys", + "wasm-bindgen", +] + [[package]] name = "h2" version = "0.4.8" @@ -1111,6 +1336,12 @@ version = "0.3.9" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d231dfb89cfffdbc30e7fc41579ed6066ad03abda9e567ccafae602b97ec5024" +[[package]] +name = "hermit-abi" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fbf6a919d6cf397374f7dfeeea91d974c7c0a7221d0d0f4f20d859d329e53fcc" + [[package]] name = "hex" version = "0.4.3" @@ -1489,6 +1720,15 @@ dependencies = [ "cpufeatures", ] +[[package]] +name = "kv-log-macro" +version = "1.0.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0de8b303297635ad57c9f5059fd9cee7a47f8e8daa09df0fcd07dd39fb22977f" +dependencies = [ + "log", +] + [[package]] name = "lalrpop" version = "0.20.2" @@ -1599,6 +1839,9 @@ name = "log" version = "0.4.26" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "30bde2b3dc3671ae49d8e2e9f044c7c005836e7a023ee57cffa25ab82764bb9e" +dependencies = [ + "value-bag", +] [[package]] name = "logos" @@ -1982,6 +2225,7 @@ dependencies = [ "rand", "serde", "thiserror 2.0.11", + "tokio", "tonic", "tracing", "tracing-forest", @@ -2287,7 +2531,7 @@ version = "1.16.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "4161fcb6d602d4d2081af7c3a45852d875a03dd337a6bfdd6e06407b61342a43" dependencies = [ - "hermit-abi", + "hermit-abi 0.3.9", "libc", ] @@ -2371,6 +2615,7 @@ version = "0.28.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "84dfad6042089c7fc1f6118b7040dc2eb4ab520abbf410b79dc481032af39570" dependencies = [ + "async-std", "async-trait", "futures-channel", "futures-executor", @@ -2398,6 +2643,12 @@ version = "4.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "1036865bb9422d3300cf723f657c2851d0e9ab12567854b1f4eba3d77decf564" +[[package]] +name = "parking" +version = "2.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f38d5652c16fde515bb1ecef450ab0f6a219d619a7274976324d5e377f7dceba" + [[package]] name = "parking_lot" version = "0.12.3" @@ -2526,12 +2777,38 @@ version = "0.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8b870d8c151b6f2fb93e84a13146138f05d02ed11c7e7c54f8826aaaf7c9f184" +[[package]] +name = "piper" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "96c8c490f422ef9a4efd2cb5b42b76c8613d7e7dfc1caf667b8a3350a5acc066" +dependencies = [ + "atomic-waker", + "fastrand", + "futures-io", +] + [[package]] name = "pkg-config" version = "0.3.31" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "953ec861398dccce10c670dfeaf3ec4911ca479e9c02154b3a215178c5f566f2" +[[package]] +name = "polling" +version = "3.7.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a604568c3202727d1507653cb121dbd627a58684eb09a820fd746bee38b4442f" +dependencies = [ + "cfg-if", + "concurrent-queue", + "hermit-abi 0.4.0", + "pin-project-lite", + "rustix", + "tracing", + "windows-sys 0.59.0", +] + [[package]] name = "powerfmt" version = "0.2.0" @@ -3177,6 +3454,15 @@ version = "1.3.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "0fda2ff0d084019ba4d7c6f371c95d8fd75ce3524c3cb8fb653a3023f6323e64" +[[package]] +name = "signal-hook-registry" +version = "1.4.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a9e9e0b4211b72e7b8b6e85c807d36c212bdb33ea8587f7569562a84df5465b1" +dependencies = [ + "libc", +] + [[package]] name = "siphasher" version = "1.0.1" @@ -3952,6 +4238,12 @@ version = "0.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" +[[package]] +name = "value-bag" +version = "1.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3ef4c4aa54d5d05a279399bfa921ec387b7aba77caf7a682ae8d86785b8fdad2" + [[package]] name = "vcpkg" version = "0.2.15" @@ -4082,6 +4374,19 @@ dependencies = [ "wasm-bindgen-shared", ] +[[package]] +name = "wasm-bindgen-futures" +version = "0.4.50" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "555d470ec0bc3bb57890405e5d4322cc9ea83cebb085523ced7be4144dac1e61" +dependencies = [ + "cfg-if", + "js-sys", + "once_cell", + "wasm-bindgen", + "web-sys", +] + [[package]] name = "wasm-bindgen-macro" version = "0.2.100" @@ -4114,6 +4419,16 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "web-sys" +version = "0.3.77" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "33b6dd2ef9186f1f2072e409e99cd22a975331a6b3591b12c764e0e55c60d5d2" +dependencies = [ + "js-sys", + "wasm-bindgen", +] + [[package]] name = "web-time" version = "1.1.0" diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index eb85fa5f5..c710d3656 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -25,7 +25,7 @@ itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } miden-node-proto = { workspace = true } -miden-node-utils = { workspace = true } +miden-node-utils = { workspace = true, features = ["testing"] } miden-objects = { workspace = true } miden-processor = { workspace = true } miden-tx = { workspace = true } diff --git a/crates/block-producer/src/mempool/tests.rs b/crates/block-producer/src/mempool/tests.rs index 8c81286bd..b5265edd4 100644 --- a/crates/block-producer/src/mempool/tests.rs +++ b/crates/block-producer/src/mempool/tests.rs @@ -16,6 +16,20 @@ impl Mempool { } } +#[tokio::test] +async fn mempool_trace() { + let (mut rx_export, _rx_shutdown) = miden_node_utils::logging::setup_test_tracing().unwrap(); + + let mut uut = Mempool::for_tests(); + let txs = MockProvenTxBuilder::sequential(); + uut.add_transaction(txs[0].clone()).unwrap(); + + let span_data = rx_export.recv().await.unwrap(); + assert_eq!(span_data.name, "mempool.add_transaction"); + assert!(span_data.attributes.iter().any(|kv| kv.key == "code.namespace".into() + && kv.value == "miden_node_block_producer::mempool".into())); +} + // BATCH FAILED TESTS // ================================================================================================ diff --git a/crates/utils/Cargo.toml b/crates/utils/Cargo.toml index f5fe8fb1a..a080ca81c 100644 --- a/crates/utils/Cargo.toml +++ b/crates/utils/Cargo.toml @@ -17,6 +17,8 @@ workspace = true [features] # Enables depedencies intended for build script generation of version metadata. vergen = ["dep:vergen", "dep:vergen-gitcl"] +# Enables utility functions for testing traces created by some other crate's stack. +testing = ["dep:tokio"] [dependencies] anyhow = { version = "1.0" } @@ -26,7 +28,7 @@ itertools = { workspace = true } miden-objects = { workspace = true } opentelemetry = { version = "0.28" } opentelemetry-otlp = { version = "0.28", default-features = false, features = ["grpc-tonic", "tls-roots", "trace"] } -opentelemetry_sdk = { version = "0.28", features = ["rt-tokio"] } +opentelemetry_sdk = { version = "0.28", features = ["rt-tokio", "testing"] } rand = { workspace = true } serde = { version = "1.0", features = ["derive"] } thiserror = { workspace = true } @@ -36,6 +38,8 @@ tracing-forest = { version = "0.1", optional = true, features = ["chrono" tracing-opentelemetry = { version = "0.29" } tracing-subscriber = { workspace = true } +# Optional dependencies enabled by `testing` feature. +tokio = { workspace = true, optional = true } # Optional dependencies enabled by `vergen` feature. # This must match the version expected by `vergen-gitcl`. vergen = { "version" = "9.0", optional = true } diff --git a/crates/utils/src/logging.rs b/crates/utils/src/logging.rs index a8a220ccd..698cbcaa9 100644 --- a/crates/utils/src/logging.rs +++ b/crates/utils/src/logging.rs @@ -3,7 +3,7 @@ use std::str::FromStr; use anyhow::Result; use opentelemetry::trace::TracerProvider as _; use opentelemetry_otlp::WithTonicConfig; -use opentelemetry_sdk::propagation::TraceContextPropagator; +use opentelemetry_sdk::{propagation::TraceContextPropagator, trace::SpanExporter}; use tracing::subscriber::Subscriber; use tracing_opentelemetry::OpenTelemetryLayer; use tracing_subscriber::{ @@ -39,7 +39,14 @@ pub fn setup_tracing(otel: OpenTelemetry) -> Result<()> { // Note: open-telemetry requires a tokio-runtime, so this _must_ be lazily evaluated (aka not // `then_some`) to avoid crashing sync callers (with OpenTelemetry::Disabled set). Examples of // such callers are tests with logging enabled. - let otel_layer = otel.is_enabled().then(open_telemetry_layer); + let otel_layer = otel.is_enabled().then(|| { + let exporter = opentelemetry_otlp::SpanExporter::builder() + .with_tonic() + .with_tls_config(tonic::transport::ClientTlsConfig::new().with_native_roots()) + .build() + .unwrap(); + open_telemetry_layer(exporter) + }); let subscriber = Registry::default() .with(stdout_layer().with_filter(env_or_default_filter())) @@ -47,17 +54,31 @@ pub fn setup_tracing(otel: OpenTelemetry) -> Result<()> { tracing::subscriber::set_global_default(subscriber).map_err(Into::into) } -fn open_telemetry_layer() -> Box + Send + Sync + 'static> +#[cfg(feature = "testing")] +pub fn setup_test_tracing() -> Result<( + tokio::sync::mpsc::UnboundedReceiver, + tokio::sync::mpsc::UnboundedReceiver<()>, +)> { + opentelemetry::global::set_text_map_propagator(TraceContextPropagator::new()); + + let (exporter, rx_export, rx_shutdown) = + opentelemetry_sdk::testing::trace::new_tokio_test_exporter(); + + let otel_layer = open_telemetry_layer(exporter); + let subscriber = Registry::default() + .with(stdout_layer().with_filter(env_or_default_filter())) + .with(otel_layer.with_filter(env_or_default_filter())); + tracing::subscriber::set_global_default(subscriber)?; + Ok((rx_export, rx_shutdown)) +} + +fn open_telemetry_layer( + exporter: impl SpanExporter + 'static, +) -> Box + Send + Sync + 'static> where S: Subscriber + Sync + Send, for<'a> S: tracing_subscriber::registry::LookupSpan<'a>, { - let exporter = opentelemetry_otlp::SpanExporter::builder() - .with_tonic() - .with_tls_config(tonic::transport::ClientTlsConfig::new().with_native_roots()) - .build() - .unwrap(); - let tracer = opentelemetry_sdk::trace::SdkTracerProvider::builder() .with_batch_exporter(exporter) .build(); From 420b385b885ba6f04688565defe774421fff486f Mon Sep 17 00:00:00 2001 From: sergerad Date: Sun, 23 Feb 2025 07:00:53 +1300 Subject: [PATCH 07/20] Use grpc trace layer and update store rpc --- Cargo.lock | 3 +++ Cargo.toml | 3 ++- crates/block-producer/Cargo.toml | 2 +- crates/block-producer/src/server.rs | 6 +++--- crates/store/Cargo.toml | 3 +++ crates/store/src/server/mod.rs | 26 +++++++++++++++++++++++--- crates/utils/Cargo.toml | 2 +- 7 files changed, 36 insertions(+), 9 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index fe0a74449..8456ea263 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2187,6 +2187,7 @@ dependencies = [ "assert_matches", "deadpool-sqlite", "hex", + "http", "miden-lib", "miden-node-proto", "miden-node-utils", @@ -2198,6 +2199,8 @@ dependencies = [ "tokio", "tokio-stream", "tonic", + "tower 0.5.2", + "tower-http 0.6.2", "tracing", "url", ] diff --git a/Cargo.toml b/Cargo.toml index 0acf8dd61..cf817fdb8 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -26,6 +26,7 @@ version = "0.8.0" [workspace.dependencies] assert_matches = { version = "1.5" } +http = { version = "1.2" } itertools = { version = "0.14" } miden-air = { version = "0.12" } miden-lib = { git = "https://github.com/0xPolygonMiden/miden-base", branch = "next" } @@ -44,7 +45,7 @@ thiserror = { version = "2.0", default-features = false } tokio = { version = "1.40", features = ["rt-multi-thread"] } tokio-stream = { version = "0.1" } tonic = { version = "0.12" } -tower = "0.5" +tower = { version = "0.5" } tower-http = { version = "0.6", features = ["trace"] } tracing = { version = "0.1" } tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt", "json"] } diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index c710d3656..0101d4fea 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -20,7 +20,7 @@ tracing-forest = ["miden-node-utils/tracing-forest"] [dependencies] async-trait = { version = "0.1" } futures = { version = "0.3" } -http = { version = "1.2" } +http = { workspace = true } itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 5fa181f18..856216a76 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -15,7 +15,7 @@ use miden_objects::{ use tokio::{net::TcpListener, sync::Mutex}; use tokio_stream::wrappers::TcpListenerStream; use tonic::Status; -use tower_http::{classify::ServerErrorsFailureClass, trace::TraceLayer}; +use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; use tracing::{debug, error, info, instrument, Span}; use crate::{ @@ -213,7 +213,7 @@ impl BlockProducerRpcServer { async fn serve(self, listener: TcpListener) -> Result<(), tonic::transport::Error> { // Configure the trace layer with callbacks. - let trace_layer = TraceLayer::new_for_http() + let trace_layer = TraceLayer::new_for_grpc() .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) .on_request(|request: &http::Request<_>, _span: &Span| { info!( @@ -227,7 +227,7 @@ impl BlockProducerRpcServer { .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { info!("response: {} {:?}", response.status(), latency); }) - .on_failure(|error: ServerErrorsFailureClass, latency: Duration, _span: &Span| { + .on_failure(|error: GrpcFailureClass, latency: Duration, _span: &Span| { error!("error: {} {:?}", error, latency); }); // Build the gRPC server with the API service and trace layer. diff --git a/crates/store/Cargo.toml b/crates/store/Cargo.toml index adc902a73..faaef6cdd 100644 --- a/crates/store/Cargo.toml +++ b/crates/store/Cargo.toml @@ -17,6 +17,7 @@ workspace = true [dependencies] deadpool-sqlite = { version = "0.9.0", features = ["rt_tokio_1"] } hex = { version = "0.4" } +http = { workspace = true } miden-lib = { workspace = true } miden-node-proto = { workspace = true } miden-node-utils = { workspace = true } @@ -28,6 +29,8 @@ thiserror = { workspace = true } tokio = { workspace = true, features = ["fs", "macros", "net", "rt-multi-thread"] } tokio-stream = { workspace = true, features = ["net"] } tonic = { workspace = true } +tower = { workspace = true } +tower-http = { workspace = true, features = ["util"] } tracing = { workspace = true } url = { workspace = true } diff --git a/crates/store/src/server/mod.rs b/crates/store/src/server/mod.rs index 2b65a1dc2..96dd2568a 100644 --- a/crates/store/src/server/mod.rs +++ b/crates/store/src/server/mod.rs @@ -1,10 +1,11 @@ -use std::sync::Arc; +use std::{sync::Arc, time::Duration}; use miden_node_proto::generated::store::api_server; use miden_node_utils::errors::ApiError; use tokio::net::TcpListener; use tokio_stream::wrappers::TcpListenerStream; -use tracing::info; +use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; +use tracing::{error, info, Span}; use crate::{blocks::BlockStore, config::StoreConfig, db::Db, state::State, COMPONENT}; @@ -61,8 +62,27 @@ impl Store { /// /// Note: this blocks until the server dies. pub async fn serve(self) -> Result<(), ApiError> { + // Configure the trace layer with callbacks. + let trace_layer = TraceLayer::new_for_grpc() + .make_span_with(miden_node_utils::tracing::grpc::store_trace_fn) + .on_request(|request: &http::Request<_>, _span: &Span| { + info!( + "request: {} {} {} {:?}", + request.method(), + request.uri().host().unwrap_or("unknown_host"), + request.uri().path(), + request.headers() + ); + }) + .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { + info!("response: {} {:?}", response.status(), latency); + }) + .on_failure(|error: GrpcFailureClass, latency: Duration, _span: &Span| { + error!("error: {} {:?}", error, latency); + }); + // Build the gRPC server with the API service and trace layer. tonic::transport::Server::builder() - .trace_fn(miden_node_utils::tracing::grpc::store_trace_fn) + .layer(trace_layer) .add_service(self.api_service) .serve_with_incoming(TcpListenerStream::new(self.listener)) .await diff --git a/crates/utils/Cargo.toml b/crates/utils/Cargo.toml index a080ca81c..428398d8f 100644 --- a/crates/utils/Cargo.toml +++ b/crates/utils/Cargo.toml @@ -23,7 +23,7 @@ testing = ["dep:tokio"] [dependencies] anyhow = { version = "1.0" } figment = { version = "0.10", features = ["env", "toml"] } -http = { version = "1.2" } +http = { workspace = true } itertools = { workspace = true } miden-objects = { workspace = true } opentelemetry = { version = "0.28" } From 7c0e0254a99d44ec23a3c5babf53e3b1bb52822b Mon Sep 17 00:00:00 2001 From: sergerad Date: Sun, 23 Feb 2025 09:56:03 +1300 Subject: [PATCH 08/20] replace unwrap logic --- crates/utils/src/logging.rs | 19 +++++++++++-------- 1 file changed, 11 insertions(+), 8 deletions(-) diff --git a/crates/utils/src/logging.rs b/crates/utils/src/logging.rs index 698cbcaa9..95ad8dc1e 100644 --- a/crates/utils/src/logging.rs +++ b/crates/utils/src/logging.rs @@ -39,14 +39,17 @@ pub fn setup_tracing(otel: OpenTelemetry) -> Result<()> { // Note: open-telemetry requires a tokio-runtime, so this _must_ be lazily evaluated (aka not // `then_some`) to avoid crashing sync callers (with OpenTelemetry::Disabled set). Examples of // such callers are tests with logging enabled. - let otel_layer = otel.is_enabled().then(|| { - let exporter = opentelemetry_otlp::SpanExporter::builder() - .with_tonic() - .with_tls_config(tonic::transport::ClientTlsConfig::new().with_native_roots()) - .build() - .unwrap(); - open_telemetry_layer(exporter) - }); + let otel_layer = { + if otel.is_enabled() { + let exporter = opentelemetry_otlp::SpanExporter::builder() + .with_tonic() + .with_tls_config(tonic::transport::ClientTlsConfig::new().with_native_roots()) + .build()?; + Some(open_telemetry_layer(exporter)) + } else { + None + } + }; let subscriber = Registry::default() .with(stdout_layer().with_filter(env_or_default_filter())) From 5d13200cc973c15cf6b6281633c7bf71943055f1 Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 14:17:11 +1300 Subject: [PATCH 09/20] Add ext trait fns and use for http requests --- crates/block-producer/Cargo.toml | 2 +- crates/block-producer/src/server.rs | 9 +++- crates/utils/src/tracing/grpc.rs | 48 +++------------------ crates/utils/src/tracing/span_ext.rs | 64 ++++++++++++++++++++++++++++ 4 files changed, 79 insertions(+), 44 deletions(-) diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index 0101d4fea..82cb706c9 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -35,7 +35,7 @@ serde = { version = "1.0", features = ["derive"] } thiserror = { workspace = true } tokio = { workspace = true, features = ["macros", "net", "rt-multi-thread", "sync", "time"] } tokio-stream = { workspace = true, features = ["net"] } -tonic = { workspace = true } +tonic = { workspace = true, features = ["transport"] } tower = { workspace = true } tower-http = { workspace = true, features = ["util"] } tracing = { workspace = true } diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 856216a76..65f644a01 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -217,7 +217,13 @@ impl BlockProducerRpcServer { .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) .on_request(|request: &http::Request<_>, _span: &Span| { info!( - "request: {} {} {} {:?}", + "request: {} {} {} {} {:?}", + request + .extensions() + .get::() + .unwrap() + .remote_addr() + .unwrap(), request.method(), request.uri().host().unwrap_or("unknown_host"), request.uri().path(), @@ -227,6 +233,7 @@ impl BlockProducerRpcServer { .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { info!("response: {} {:?}", response.status(), latency); }) + //.on_failure(|error: ServerErrorsFailureClass, latency: Duration, _span: &Span| { .on_failure(|error: GrpcFailureClass, latency: Duration, _span: &Span| { error!("error: {} {:?}", error, latency); }); diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index ab343317f..2791300a5 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -1,4 +1,4 @@ -use tracing_opentelemetry::OpenTelemetrySpanExt; +use super::OpenTelemetrySpanExt; /// A [`trace_fn`](tonic::transport::server::Server) implementation for the block producer which /// adds open-telemetry information to the span. @@ -13,7 +13,9 @@ pub fn block_producer_trace_fn(request: &http::Request) -> tracing::Span { tracing::info_span!("block-producer.rpc/Unknown") }; - add_otel_span_attributes(span, request) + span.set_parent(request); + span.set_http_attributes(request); + span } /// A [`trace_fn`](tonic::transport::server::Server) implementation for the store which adds @@ -41,26 +43,8 @@ pub fn store_trace_fn(request: &http::Request) -> tracing::Span { _ => tracing::info_span!("store.rpc/Unknown"), }; - add_otel_span_attributes(span, request) -} - -/// Adds remote tracing context to the span. -/// -/// Could be expanded in the future by adding in more open-telemetry properties. -fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) -> tracing::Span { - // Pull the open-telemetry parent context using the HTTP extractor. We could make a more - // generic gRPC extractor by utilising the gRPC metadata. However that - // (a) requires cloning headers, - // (b) we would have to write this ourselves, and - // (c) gRPC metadata is transferred using HTTP headers in any case. - use tracing_opentelemetry::OpenTelemetrySpanExt; - let otel_ctx = opentelemetry::global::get_text_map_propagator(|propagator| { - propagator.extract(&MetadataExtractor(&tonic::metadata::MetadataMap::from_headers( - request.headers().clone(), - ))) - }); - span.set_parent(otel_ctx); - + span.set_parent(request); + span.set_http_attributes(request); span } @@ -82,26 +66,6 @@ impl tonic::service::Interceptor for OtelInterceptor { } } -struct MetadataExtractor<'a>(&'a tonic::metadata::MetadataMap); -impl opentelemetry::propagation::Extractor for MetadataExtractor<'_> { - /// Get a value for a key from the `MetadataMap`. If the value can't be converted to &str, - /// returns None - fn get(&self, key: &str) -> Option<&str> { - self.0.get(key).and_then(|metadata| metadata.to_str().ok()) - } - - /// Collect all the keys from the `MetadataMap`. - fn keys(&self) -> Vec<&str> { - self.0 - .keys() - .map(|key| match key { - tonic::metadata::KeyRef::Ascii(v) => v.as_str(), - tonic::metadata::KeyRef::Binary(v) => v.as_str(), - }) - .collect::>() - } -} - struct MetadataInjector<'a>(&'a mut tonic::metadata::MetadataMap); impl opentelemetry::propagation::Injector for MetadataInjector<'_> { /// Set a key and value in the `MetadataMap`. Does nothing if the key or value are not valid diff --git a/crates/utils/src/tracing/span_ext.rs b/crates/utils/src/tracing/span_ext.rs index a21150ac0..78d54c206 100644 --- a/crates/utils/src/tracing/span_ext.rs +++ b/crates/utils/src/tracing/span_ext.rs @@ -1,4 +1,5 @@ use core::time::Duration; +use std::net::SocketAddr; use miden_objects::{block::BlockNumber, Digest}; use opentelemetry::{trace::Status, Key, Value}; @@ -8,6 +9,16 @@ pub trait ToValue { fn to_value(&self) -> Value; } +impl ToValue for Option { + fn to_value(&self) -> Value { + if let Some(socket_addr) = self { + socket_addr.to_string().into() + } else { + "no_remote_addr".into() + } + } +} + impl ToValue for Duration { fn to_value(&self) -> Value { self.as_secs_f64().into() @@ -48,14 +59,37 @@ impl ToValue for i64 { /// /// This is a sealed trait. It and cannot be implemented outside of this module. pub trait OpenTelemetrySpanExt: private::Sealed { + fn set_parent(&self, request: &http::Request); fn set_attribute(&self, key: impl Into, value: impl ToValue); + fn set_http_attributes(&self, request: &http::Request); fn set_error(&self, err: &dyn std::error::Error); + fn context(&self) -> opentelemetry::Context; } impl OpenTelemetrySpanExt for S where S: tracing_opentelemetry::OpenTelemetrySpanExt, { + /// ... + fn set_parent(&self, request: &http::Request) { + // Pull the open-telemetry parent context using the HTTP extractor. We could make a more + // generic gRPC extractor by utilising the gRPC metadata. However that + // (a) requires cloning headers, + // (b) we would have to write this ourselves, and + // (c) gRPC metadata is transferred using HTTP headers in any case. + let otel_ctx = opentelemetry::global::get_text_map_propagator(|propagator| { + propagator.extract(&MetadataExtractor(&tonic::metadata::MetadataMap::from_headers( + request.headers().clone(), + ))) + }); + tracing_opentelemetry::OpenTelemetrySpanExt::set_parent(self, otel_ctx); + } + + /// ... + fn context(&self) -> opentelemetry::Context { + tracing_opentelemetry::OpenTelemetrySpanExt::context(self) + } + /// Sets an attribute on `Span`. /// /// Implementations for `ToValue` should be added to this crate (miden-node-utils). @@ -63,6 +97,15 @@ where tracing_opentelemetry::OpenTelemetrySpanExt::set_attribute(self, key, value.to_value()); } + /// ... + fn set_http_attributes(&self, request: &http::Request) { + let remote_addr = request + .extensions() + .get::() + .and_then(tonic::transport::server::TcpConnectInfo::remote_addr); + OpenTelemetrySpanExt::set_attribute(self, "remote_addr", remote_addr); + } + /// Sets a status on `Span` based on an error. fn set_error(&self, err: &dyn std::error::Error) { // Coalesce all sources into one string. @@ -82,3 +125,24 @@ mod private { pub trait Sealed {} impl Sealed for S where S: tracing_opentelemetry::OpenTelemetrySpanExt {} } + +/// ... +struct MetadataExtractor<'a>(pub(crate) &'a tonic::metadata::MetadataMap); +impl opentelemetry::propagation::Extractor for MetadataExtractor<'_> { + /// Get a value for a key from the `MetadataMap`. If the value can't be converted to &str, + /// returns None + fn get(&self, key: &str) -> Option<&str> { + self.0.get(key).and_then(|metadata| metadata.to_str().ok()) + } + + /// Collect all the keys from the `MetadataMap`. + fn keys(&self) -> Vec<&str> { + self.0 + .keys() + .map(|key| match key { + tonic::metadata::KeyRef::Ascii(v) => v.as_str(), + tonic::metadata::KeyRef::Binary(v) => v.as_str(), + }) + .collect::>() + } +} From 89c934e9876c679c8591a95419d99a5213dc2070 Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 16:06:01 +1300 Subject: [PATCH 10/20] Use default callbacks --- crates/block-producer/src/server.rs | 29 ++--------------------------- crates/store/src/server/mod.rs | 28 +++++----------------------- 2 files changed, 7 insertions(+), 50 deletions(-) diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 65f644a01..48c1e3407 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -7,7 +7,7 @@ use miden_node_proto::generated::{ use miden_node_utils::{ errors::ApiError, formatting::{format_input_notes, format_output_notes}, - tracing::grpc::OtelInterceptor, + tracing::grpc::{block_producer_trace_fn, OtelInterceptor}, }; use miden_objects::{ block::BlockNumber, transaction::ProvenTransaction, utils::serde::Deserializable, @@ -212,34 +212,9 @@ impl BlockProducerRpcServer { } async fn serve(self, listener: TcpListener) -> Result<(), tonic::transport::Error> { - // Configure the trace layer with callbacks. - let trace_layer = TraceLayer::new_for_grpc() - .make_span_with(miden_node_utils::tracing::grpc::block_producer_trace_fn) - .on_request(|request: &http::Request<_>, _span: &Span| { - info!( - "request: {} {} {} {} {:?}", - request - .extensions() - .get::() - .unwrap() - .remote_addr() - .unwrap(), - request.method(), - request.uri().host().unwrap_or("unknown_host"), - request.uri().path(), - request.headers() - ); - }) - .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { - info!("response: {} {:?}", response.status(), latency); - }) - //.on_failure(|error: ServerErrorsFailureClass, latency: Duration, _span: &Span| { - .on_failure(|error: GrpcFailureClass, latency: Duration, _span: &Span| { - error!("error: {} {:?}", error, latency); - }); // Build the gRPC server with the API service and trace layer. tonic::transport::Server::builder() - .layer(trace_layer) + .layer(TraceLayer::new_for_grpc().make_span_with(block_producer_trace_fn)) .add_service(api_server::ApiServer::new(self)) .serve_with_incoming(TcpListenerStream::new(listener)) .await diff --git a/crates/store/src/server/mod.rs b/crates/store/src/server/mod.rs index 96dd2568a..a3c1f009d 100644 --- a/crates/store/src/server/mod.rs +++ b/crates/store/src/server/mod.rs @@ -1,11 +1,11 @@ -use std::{sync::Arc, time::Duration}; +use std::sync::Arc; use miden_node_proto::generated::store::api_server; -use miden_node_utils::errors::ApiError; +use miden_node_utils::{errors::ApiError, tracing::grpc::store_trace_fn}; use tokio::net::TcpListener; use tokio_stream::wrappers::TcpListenerStream; -use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; -use tracing::{error, info, Span}; +use tower_http::trace::TraceLayer; +use tracing::info; use crate::{blocks::BlockStore, config::StoreConfig, db::Db, state::State, COMPONENT}; @@ -62,27 +62,9 @@ impl Store { /// /// Note: this blocks until the server dies. pub async fn serve(self) -> Result<(), ApiError> { - // Configure the trace layer with callbacks. - let trace_layer = TraceLayer::new_for_grpc() - .make_span_with(miden_node_utils::tracing::grpc::store_trace_fn) - .on_request(|request: &http::Request<_>, _span: &Span| { - info!( - "request: {} {} {} {:?}", - request.method(), - request.uri().host().unwrap_or("unknown_host"), - request.uri().path(), - request.headers() - ); - }) - .on_response(|response: &http::Response<_>, latency: Duration, _span: &Span| { - info!("response: {} {:?}", response.status(), latency); - }) - .on_failure(|error: GrpcFailureClass, latency: Duration, _span: &Span| { - error!("error: {} {:?}", error, latency); - }); // Build the gRPC server with the API service and trace layer. tonic::transport::Server::builder() - .layer(trace_layer) + .layer(TraceLayer::new_for_grpc().make_span_with(store_trace_fn)) .add_service(self.api_service) .serve_with_incoming(TcpListenerStream::new(self.listener)) .await From 8c195dbbc6900ddb429efc7c8760fe79e19baf75 Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 16:10:24 +1300 Subject: [PATCH 11/20] RM tests --- crates/block-producer/src/mempool/tests.rs | 14 -------------- 1 file changed, 14 deletions(-) diff --git a/crates/block-producer/src/mempool/tests.rs b/crates/block-producer/src/mempool/tests.rs index b5265edd4..8c81286bd 100644 --- a/crates/block-producer/src/mempool/tests.rs +++ b/crates/block-producer/src/mempool/tests.rs @@ -16,20 +16,6 @@ impl Mempool { } } -#[tokio::test] -async fn mempool_trace() { - let (mut rx_export, _rx_shutdown) = miden_node_utils::logging::setup_test_tracing().unwrap(); - - let mut uut = Mempool::for_tests(); - let txs = MockProvenTxBuilder::sequential(); - uut.add_transaction(txs[0].clone()).unwrap(); - - let span_data = rx_export.recv().await.unwrap(); - assert_eq!(span_data.name, "mempool.add_transaction"); - assert!(span_data.attributes.iter().any(|kv| kv.key == "code.namespace".into() - && kv.value == "miden_node_block_producer::mempool".into())); -} - // BATCH FAILED TESTS // ================================================================================================ From 9f3ede761b7a77d75a511bd5e26142a0a1065eba Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 20:25:23 +1300 Subject: [PATCH 12/20] Comments --- crates/utils/src/tracing/span_ext.rs | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/crates/utils/src/tracing/span_ext.rs b/crates/utils/src/tracing/span_ext.rs index 78d54c206..86c85eb00 100644 --- a/crates/utils/src/tracing/span_ext.rs +++ b/crates/utils/src/tracing/span_ext.rs @@ -70,7 +70,7 @@ impl OpenTelemetrySpanExt for S where S: tracing_opentelemetry::OpenTelemetrySpanExt, { - /// ... + /// Sets the parent context by extracting HTTP metadata from the request. fn set_parent(&self, request: &http::Request) { // Pull the open-telemetry parent context using the HTTP extractor. We could make a more // generic gRPC extractor by utilising the gRPC metadata. However that @@ -85,7 +85,7 @@ where tracing_opentelemetry::OpenTelemetrySpanExt::set_parent(self, otel_ctx); } - /// ... + /// Returns the context of `Span`. fn context(&self) -> opentelemetry::Context { tracing_opentelemetry::OpenTelemetrySpanExt::context(self) } @@ -97,7 +97,7 @@ where tracing_opentelemetry::OpenTelemetrySpanExt::set_attribute(self, key, value.to_value()); } - /// ... + /// Sets standard attributes to the `Span` based on an associated HTTP request. fn set_http_attributes(&self, request: &http::Request) { let remote_addr = request .extensions() @@ -126,8 +126,8 @@ mod private { impl Sealed for S where S: tracing_opentelemetry::OpenTelemetrySpanExt {} } -/// ... -struct MetadataExtractor<'a>(pub(crate) &'a tonic::metadata::MetadataMap); +/// Facilitates Open Telemetry metadata extraction for Tonic `MetadataMap`. +struct MetadataExtractor<'a>(&'a tonic::metadata::MetadataMap); impl opentelemetry::propagation::Extractor for MetadataExtractor<'_> { /// Get a value for a key from the `MetadataMap`. If the value can't be converted to &str, /// returns None From d89188223f3b12d974a8144de85da5a58624702c Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 21:14:42 +1300 Subject: [PATCH 13/20] Fmt --- crates/block-producer/src/server.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/crates/block-producer/src/server.rs b/crates/block-producer/src/server.rs index 48c1e3407..e3dc923e4 100644 --- a/crates/block-producer/src/server.rs +++ b/crates/block-producer/src/server.rs @@ -1,4 +1,4 @@ -use std::{collections::HashMap, time::Duration}; +use std::collections::HashMap; use miden_node_proto::generated::{ block_producer::api_server, requests::SubmitProvenTransactionRequest, @@ -15,8 +15,8 @@ use miden_objects::{ use tokio::{net::TcpListener, sync::Mutex}; use tokio_stream::wrappers::TcpListenerStream; use tonic::Status; -use tower_http::{classify::GrpcFailureClass, trace::TraceLayer}; -use tracing::{debug, error, info, instrument, Span}; +use tower_http::trace::TraceLayer; +use tracing::{debug, info, instrument}; use crate::{ batch_builder::BatchBuilder, From 2f6c71d66590a1d8efd04e772fc8426483258824 Mon Sep 17 00:00:00 2001 From: sergerad Date: Thu, 27 Feb 2025 21:56:42 +1300 Subject: [PATCH 14/20] Unused deps --- Cargo.lock | 4 ---- crates/block-producer/Cargo.toml | 2 -- crates/store/Cargo.toml | 2 -- 3 files changed, 8 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 8456ea263..8daabac74 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2119,7 +2119,6 @@ dependencies = [ "assert_matches", "async-trait", "futures", - "http", "itertools 0.14.0", "miden-air", "miden-block-prover", @@ -2139,7 +2138,6 @@ dependencies = [ "tokio", "tokio-stream", "tonic", - "tower 0.5.2", "tower-http 0.6.2", "tracing", "url", @@ -2187,7 +2185,6 @@ dependencies = [ "assert_matches", "deadpool-sqlite", "hex", - "http", "miden-lib", "miden-node-proto", "miden-node-utils", @@ -2199,7 +2196,6 @@ dependencies = [ "tokio", "tokio-stream", "tonic", - "tower 0.5.2", "tower-http 0.6.2", "tracing", "url", diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index 82cb706c9..022e496dc 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -20,7 +20,6 @@ tracing-forest = ["miden-node-utils/tracing-forest"] [dependencies] async-trait = { version = "0.1" } futures = { version = "0.3" } -http = { workspace = true } itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } @@ -36,7 +35,6 @@ thiserror = { workspace = true } tokio = { workspace = true, features = ["macros", "net", "rt-multi-thread", "sync", "time"] } tokio-stream = { workspace = true, features = ["net"] } tonic = { workspace = true, features = ["transport"] } -tower = { workspace = true } tower-http = { workspace = true, features = ["util"] } tracing = { workspace = true } url = { workspace = true } diff --git a/crates/store/Cargo.toml b/crates/store/Cargo.toml index faaef6cdd..3ce5c5de0 100644 --- a/crates/store/Cargo.toml +++ b/crates/store/Cargo.toml @@ -17,7 +17,6 @@ workspace = true [dependencies] deadpool-sqlite = { version = "0.9.0", features = ["rt_tokio_1"] } hex = { version = "0.4" } -http = { workspace = true } miden-lib = { workspace = true } miden-node-proto = { workspace = true } miden-node-utils = { workspace = true } @@ -29,7 +28,6 @@ thiserror = { workspace = true } tokio = { workspace = true, features = ["fs", "macros", "net", "rt-multi-thread"] } tokio-stream = { workspace = true, features = ["net"] } tonic = { workspace = true } -tower = { workspace = true } tower-http = { workspace = true, features = ["util"] } tracing = { workspace = true } url = { workspace = true } From 3d4a941bcb8e4c020a91b8221d7147d6705f3596 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 28 Feb 2025 09:13:01 +1300 Subject: [PATCH 15/20] Undo trait fns --- crates/utils/src/tracing/grpc.rs | 55 ++++++++++++++++++++++++---- crates/utils/src/tracing/span_ext.rs | 53 --------------------------- 2 files changed, 48 insertions(+), 60 deletions(-) diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index 2791300a5..8c08af0c2 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -1,5 +1,3 @@ -use super::OpenTelemetrySpanExt; - /// A [`trace_fn`](tonic::transport::server::Server) implementation for the block producer which /// adds open-telemetry information to the span. /// @@ -13,9 +11,7 @@ pub fn block_producer_trace_fn(request: &http::Request) -> tracing::Span { tracing::info_span!("block-producer.rpc/Unknown") }; - span.set_parent(request); - span.set_http_attributes(request); - span + add_otel_span_attributes(span, request) } /// A [`trace_fn`](tonic::transport::server::Server) implementation for the store which adds @@ -43,8 +39,32 @@ pub fn store_trace_fn(request: &http::Request) -> tracing::Span { _ => tracing::info_span!("store.rpc/Unknown"), }; - span.set_parent(request); - span.set_http_attributes(request); + add_otel_span_attributes(span, request) +} + +/// Adds remote tracing context to the span. +/// +/// Could be expanded in the future by adding in more open-telemetry properties. +fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) -> tracing::Span { + // Pull the open-telemetry parent context using the HTTP extractor. We could make a more + // generic gRPC extractor by utilising the gRPC metadata. However that + // (a) requires cloning headers, + // (b) we would have to write this ourselves, and + // (c) gRPC metadata is transferred using HTTP headers in any case. + let otel_ctx = opentelemetry::global::get_text_map_propagator(|propagator| { + propagator.extract(&MetadataExtractor(&tonic::metadata::MetadataMap::from_headers( + request.headers().clone(), + ))) + }); + tracing_opentelemetry::OpenTelemetrySpanExt::set_parent(&span, otel_ctx); + + // Set HTTP attributes: https://opentelemetry.io/docs/specs/semconv/rpc/rpc-spans/#server-attributes + let remote_addr = request + .extensions() + .get::() + .and_then(tonic::transport::server::TcpConnectInfo::remote_addr); + super::OpenTelemetrySpanExt::set_attribute(&span, "remote_addr", remote_addr); + span } @@ -57,6 +77,7 @@ impl tonic::service::Interceptor for OtelInterceptor { &mut self, mut request: tonic::Request<()>, ) -> Result, tonic::Status> { + use tracing_opentelemetry::OpenTelemetrySpanExt; let ctx = tracing::Span::current().context(); opentelemetry::global::get_text_map_propagator(|propagator| { propagator.inject_context(&ctx, &mut MetadataInjector(request.metadata_mut())); @@ -66,6 +87,26 @@ impl tonic::service::Interceptor for OtelInterceptor { } } +struct MetadataExtractor<'a>(&'a tonic::metadata::MetadataMap); +impl opentelemetry::propagation::Extractor for MetadataExtractor<'_> { + /// Get a value for a key from the `MetadataMap`. If the value can't be converted to &str, + /// returns None + fn get(&self, key: &str) -> Option<&str> { + self.0.get(key).and_then(|metadata| metadata.to_str().ok()) + } + + /// Collect all the keys from the `MetadataMap`. + fn keys(&self) -> Vec<&str> { + self.0 + .keys() + .map(|key| match key { + tonic::metadata::KeyRef::Ascii(v) => v.as_str(), + tonic::metadata::KeyRef::Binary(v) => v.as_str(), + }) + .collect::>() + } +} + struct MetadataInjector<'a>(&'a mut tonic::metadata::MetadataMap); impl opentelemetry::propagation::Injector for MetadataInjector<'_> { /// Set a key and value in the `MetadataMap`. Does nothing if the key or value are not valid diff --git a/crates/utils/src/tracing/span_ext.rs b/crates/utils/src/tracing/span_ext.rs index 86c85eb00..d7c7f7252 100644 --- a/crates/utils/src/tracing/span_ext.rs +++ b/crates/utils/src/tracing/span_ext.rs @@ -59,37 +59,14 @@ impl ToValue for i64 { /// /// This is a sealed trait. It and cannot be implemented outside of this module. pub trait OpenTelemetrySpanExt: private::Sealed { - fn set_parent(&self, request: &http::Request); fn set_attribute(&self, key: impl Into, value: impl ToValue); - fn set_http_attributes(&self, request: &http::Request); fn set_error(&self, err: &dyn std::error::Error); - fn context(&self) -> opentelemetry::Context; } impl OpenTelemetrySpanExt for S where S: tracing_opentelemetry::OpenTelemetrySpanExt, { - /// Sets the parent context by extracting HTTP metadata from the request. - fn set_parent(&self, request: &http::Request) { - // Pull the open-telemetry parent context using the HTTP extractor. We could make a more - // generic gRPC extractor by utilising the gRPC metadata. However that - // (a) requires cloning headers, - // (b) we would have to write this ourselves, and - // (c) gRPC metadata is transferred using HTTP headers in any case. - let otel_ctx = opentelemetry::global::get_text_map_propagator(|propagator| { - propagator.extract(&MetadataExtractor(&tonic::metadata::MetadataMap::from_headers( - request.headers().clone(), - ))) - }); - tracing_opentelemetry::OpenTelemetrySpanExt::set_parent(self, otel_ctx); - } - - /// Returns the context of `Span`. - fn context(&self) -> opentelemetry::Context { - tracing_opentelemetry::OpenTelemetrySpanExt::context(self) - } - /// Sets an attribute on `Span`. /// /// Implementations for `ToValue` should be added to this crate (miden-node-utils). @@ -97,15 +74,6 @@ where tracing_opentelemetry::OpenTelemetrySpanExt::set_attribute(self, key, value.to_value()); } - /// Sets standard attributes to the `Span` based on an associated HTTP request. - fn set_http_attributes(&self, request: &http::Request) { - let remote_addr = request - .extensions() - .get::() - .and_then(tonic::transport::server::TcpConnectInfo::remote_addr); - OpenTelemetrySpanExt::set_attribute(self, "remote_addr", remote_addr); - } - /// Sets a status on `Span` based on an error. fn set_error(&self, err: &dyn std::error::Error) { // Coalesce all sources into one string. @@ -125,24 +93,3 @@ mod private { pub trait Sealed {} impl Sealed for S where S: tracing_opentelemetry::OpenTelemetrySpanExt {} } - -/// Facilitates Open Telemetry metadata extraction for Tonic `MetadataMap`. -struct MetadataExtractor<'a>(&'a tonic::metadata::MetadataMap); -impl opentelemetry::propagation::Extractor for MetadataExtractor<'_> { - /// Get a value for a key from the `MetadataMap`. If the value can't be converted to &str, - /// returns None - fn get(&self, key: &str) -> Option<&str> { - self.0.get(key).and_then(|metadata| metadata.to_str().ok()) - } - - /// Collect all the keys from the `MetadataMap`. - fn keys(&self) -> Vec<&str> { - self.0 - .keys() - .map(|key| match key { - tonic::metadata::KeyRef::Ascii(v) => v.as_str(), - tonic::metadata::KeyRef::Binary(v) => v.as_str(), - }) - .collect::>() - } -} From 2f52feaeb37984f8e8f86f4549a5987c576d91da Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 28 Feb 2025 11:15:05 +1300 Subject: [PATCH 16/20] Add Otel attributes --- crates/utils/src/tracing/grpc.rs | 68 ++++++++++++++++++++-------- crates/utils/src/tracing/span_ext.rs | 64 ++++++++++++++++---------- 2 files changed, 88 insertions(+), 44 deletions(-) diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index 8c08af0c2..ad2cc365a 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -1,3 +1,14 @@ +/// Creates a [`tracing::Span`] based on RPC service and method name. +macro_rules! rpc_span { + ($service:expr, $method:expr) => { + tracing::info_span!( + concat!($service, "/", $method), + rpc.service = $service, + rpc.method = $method + ) + }; +} + /// A [`trace_fn`](tonic::transport::server::Server) implementation for the block producer which /// adds open-telemetry information to the span. /// @@ -6,9 +17,9 @@ /// to the client's origin trace. pub fn block_producer_trace_fn(request: &http::Request) -> tracing::Span { let span = if let Some("SubmitProvenTransaction") = request.uri().path().rsplit('/').next() { - tracing::info_span!("block-producer.rpc/SubmitProvenTransaction") + rpc_span!("block-producer.rpc", "SubmitProvenTransaction") } else { - tracing::info_span!("block-producer.rpc/Unknown") + rpc_span!("block-producer.rpc", "Unknown") }; add_otel_span_attributes(span, request) @@ -22,21 +33,21 @@ pub fn block_producer_trace_fn(request: &http::Request) -> tracing::Span { /// client's origin trace. pub fn store_trace_fn(request: &http::Request) -> tracing::Span { let span = match request.uri().path().rsplit('/').next() { - Some("ApplyBlock") => tracing::info_span!("store.rpc/ApplyBlock"), - Some("CheckNullifiers") => tracing::info_span!("store.rpc/CheckNullifiers"), - Some("CheckNullifiersByPrefix") => tracing::info_span!("store.rpc/CheckNullifiersByPrefix"), - Some("GetAccountDetails") => tracing::info_span!("store.rpc/GetAccountDetails"), - Some("GetAccountProofs") => tracing::info_span!("store.rpc/GetAccountProofs"), - Some("GetAccountStateDelta") => tracing::info_span!("store.rpc/GetAccountStateDelta"), - Some("GetBlockByNumber") => tracing::info_span!("store.rpc/GetBlockByNumber"), - Some("GetBlockHeaderByNumber") => tracing::info_span!("store.rpc/GetBlockHeaderByNumber"), - Some("GetBlockInputs") => tracing::info_span!("store.rpc/GetBlockInputs"), - Some("GetBatchInputs") => tracing::info_span!("store.rpc/GetBatchInputs"), - Some("GetNotesById") => tracing::info_span!("store.rpc/GetNotesById"), - Some("GetTransactionInputs") => tracing::info_span!("store.rpc/GetTransactionInputs"), - Some("SyncNotes") => tracing::info_span!("store.rpc/SyncNotes"), - Some("SyncState") => tracing::info_span!("store.rpc/SyncState"), - _ => tracing::info_span!("store.rpc/Unknown"), + Some("ApplyBlock") => rpc_span!("store.rpc", "ApplyBlock"), + Some("CheckNullifiers") => rpc_span!("store.rpc", "CheckNullifiers"), + Some("CheckNullifiersByPrefix") => rpc_span!("store.rpc", "CheckNullifiersByPrefix"), + Some("GetAccountDetails") => rpc_span!("store.rpc", "GetAccountDetails"), + Some("GetAccountProofs") => rpc_span!("store.rpc", "GetAccountProofs"), + Some("GetAccountStateDelta") => rpc_span!("store.rpc", "GetAccountStateDelta"), + Some("GetBlockByNumber") => rpc_span!("store.rpc", "GetBlockByNumber"), + Some("GetBlockHeaderByNumber") => rpc_span!("store.rpc", "GetBlockHeaderByNumber"), + Some("GetBlockInputs") => rpc_span!("store.rpc", "GetBlockInputs"), + Some("GetBatchInputs") => rpc_span!("store.rpc", "GetBatchInputs"), + Some("GetNotesById") => rpc_span!("store.rpc", "GetNotesById"), + Some("GetTransactionInputs") => rpc_span!("store.rpc", "GetTransactionInputs"), + Some("SyncNotes") => rpc_span!("store.rpc", "SyncNotes"), + Some("SyncState") => rpc_span!("store.rpc", "SyncState"), + _ => rpc_span!("store.rpc", "Unknown"), }; add_otel_span_attributes(span, request) @@ -46,6 +57,7 @@ pub fn store_trace_fn(request: &http::Request) -> tracing::Span { /// /// Could be expanded in the future by adding in more open-telemetry properties. fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) -> tracing::Span { + use super::OpenTelemetrySpanExt; // Pull the open-telemetry parent context using the HTTP extractor. We could make a more // generic gRPC extractor by utilising the gRPC metadata. However that // (a) requires cloning headers, @@ -58,12 +70,30 @@ fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) }); tracing_opentelemetry::OpenTelemetrySpanExt::set_parent(&span, otel_ctx); - // Set HTTP attributes: https://opentelemetry.io/docs/specs/semconv/rpc/rpc-spans/#server-attributes + // Set HTTP attributes. + // See https://opentelemetry.io/docs/specs/semconv/rpc/rpc-spans/#server-attributes. + span.set_attribute("rpc.system", "grpc"); + if let Some(host) = request.uri().host() { + span.set_attribute("server.address", host); + } + if let Some(host_port) = request.uri().port() { + span.set_attribute("server.port", host_port.as_str()); + } let remote_addr = request .extensions() .get::() .and_then(tonic::transport::server::TcpConnectInfo::remote_addr); - super::OpenTelemetrySpanExt::set_attribute(&span, "remote_addr", remote_addr); + if let Some(addr) = remote_addr { + span.set_attribute("client.address", addr.ip()); + span.set_attribute("client.port", addr.port()); + span.set_attribute("network.peer.address", addr.ip()); + span.set_attribute("network.peer.port", addr.port()); + span.set_attribute("network.transport", "tcp"); + match addr.ip() { + std::net::IpAddr::V4(_) => span.set_attribute("network.type", "ipv4"), + std::net::IpAddr::V6(_) => span.set_attribute("network.type", "ipv6"), + } + } span } diff --git a/crates/utils/src/tracing/span_ext.rs b/crates/utils/src/tracing/span_ext.rs index d7c7f7252..77b359eda 100644 --- a/crates/utils/src/tracing/span_ext.rs +++ b/crates/utils/src/tracing/span_ext.rs @@ -1,5 +1,5 @@ use core::time::Duration; -use std::net::SocketAddr; +use std::net::IpAddr; use miden_objects::{block::BlockNumber, Digest}; use opentelemetry::{trace::Status, Key, Value}; @@ -9,16 +9,6 @@ pub trait ToValue { fn to_value(&self) -> Value; } -impl ToValue for Option { - fn to_value(&self) -> Value { - if let Some(socket_addr) = self { - socket_addr.to_string().into() - } else { - "no_remote_addr".into() - } - } -} - impl ToValue for Duration { fn to_value(&self) -> Value { self.as_secs_f64().into() @@ -31,29 +21,53 @@ impl ToValue for Digest { } } -impl ToValue for f64 { - fn to_value(&self) -> Value { - (*self).into() - } -} - impl ToValue for BlockNumber { fn to_value(&self) -> Value { i64::from(self.as_u32()).into() } } -impl ToValue for u32 { - fn to_value(&self) -> Value { - i64::from(*self).into() - } +/// Generates `impl ToValue` blocks for types that are `ToString`. +macro_rules! impl_to_string_to_value { + ($($t:ty),*) => { + $( + impl ToValue for $t { + fn to_value(&self) -> Value { + self.to_string().into() + } + } + )* + }; } +impl_to_string_to_value!(IpAddr, &str); -impl ToValue for i64 { - fn to_value(&self) -> Value { - (*self).into() - } +/// Generates `impl ToValue` blocks for integer types. +macro_rules! impl_int_to_value { + ($($t:ty),*) => { + $( + impl ToValue for $t { + fn to_value(&self) -> Value { + i64::from(*self).into() + } + } + )* + }; +} +impl_int_to_value!(u16, u32, i64); + +/// Generates `impl ToValue` blocks for types that are `Into`. +macro_rules! impl_to_value { + ($($t:ty),*) => { + $( + impl ToValue for $t { + fn to_value(&self) -> Value { + (*self).into() + } + } + )* + }; } +impl_to_value!(f64); /// Utility functions based on [`tracing_opentelemetry::OpenTelemetrySpanExt`]. /// From 099764ea656d18b07ed07befe6b591ac55331643 Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 28 Feb 2025 12:43:29 +1300 Subject: [PATCH 17/20] RM tracing test src --- crates/block-producer/Cargo.toml | 1 - crates/utils/Cargo.toml | 4 ---- crates/utils/src/logging.rs | 18 ------------------ 3 files changed, 23 deletions(-) diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index 022e496dc..128e8be85 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -24,7 +24,6 @@ itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } miden-node-proto = { workspace = true } -miden-node-utils = { workspace = true, features = ["testing"] } miden-objects = { workspace = true } miden-processor = { workspace = true } miden-tx = { workspace = true } diff --git a/crates/utils/Cargo.toml b/crates/utils/Cargo.toml index 428398d8f..c35bfd41a 100644 --- a/crates/utils/Cargo.toml +++ b/crates/utils/Cargo.toml @@ -17,8 +17,6 @@ workspace = true [features] # Enables depedencies intended for build script generation of version metadata. vergen = ["dep:vergen", "dep:vergen-gitcl"] -# Enables utility functions for testing traces created by some other crate's stack. -testing = ["dep:tokio"] [dependencies] anyhow = { version = "1.0" } @@ -38,8 +36,6 @@ tracing-forest = { version = "0.1", optional = true, features = ["chrono" tracing-opentelemetry = { version = "0.29" } tracing-subscriber = { workspace = true } -# Optional dependencies enabled by `testing` feature. -tokio = { workspace = true, optional = true } # Optional dependencies enabled by `vergen` feature. # This must match the version expected by `vergen-gitcl`. vergen = { "version" = "9.0", optional = true } diff --git a/crates/utils/src/logging.rs b/crates/utils/src/logging.rs index 95ad8dc1e..cec4f6160 100644 --- a/crates/utils/src/logging.rs +++ b/crates/utils/src/logging.rs @@ -57,24 +57,6 @@ pub fn setup_tracing(otel: OpenTelemetry) -> Result<()> { tracing::subscriber::set_global_default(subscriber).map_err(Into::into) } -#[cfg(feature = "testing")] -pub fn setup_test_tracing() -> Result<( - tokio::sync::mpsc::UnboundedReceiver, - tokio::sync::mpsc::UnboundedReceiver<()>, -)> { - opentelemetry::global::set_text_map_propagator(TraceContextPropagator::new()); - - let (exporter, rx_export, rx_shutdown) = - opentelemetry_sdk::testing::trace::new_tokio_test_exporter(); - - let otel_layer = open_telemetry_layer(exporter); - let subscriber = Registry::default() - .with(stdout_layer().with_filter(env_or_default_filter())) - .with(otel_layer.with_filter(env_or_default_filter())); - tracing::subscriber::set_global_default(subscriber)?; - Ok((rx_export, rx_shutdown)) -} - fn open_telemetry_layer( exporter: impl SpanExporter + 'static, ) -> Box + Send + Sync + 'static> From 20ee988ca1b49e38ff8f172bba67a40fd12ee9ea Mon Sep 17 00:00:00 2001 From: sergerad Date: Fri, 28 Feb 2025 18:58:47 +1300 Subject: [PATCH 18/20] Fix toml --- Cargo.lock | 1 - crates/block-producer/Cargo.toml | 1 + 2 files changed, 1 insertion(+), 1 deletion(-) diff --git a/Cargo.lock b/Cargo.lock index 8daabac74..a6456d948 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2224,7 +2224,6 @@ dependencies = [ "rand", "serde", "thiserror 2.0.11", - "tokio", "tonic", "tracing", "tracing-forest", diff --git a/crates/block-producer/Cargo.toml b/crates/block-producer/Cargo.toml index 128e8be85..f6d0789b6 100644 --- a/crates/block-producer/Cargo.toml +++ b/crates/block-producer/Cargo.toml @@ -24,6 +24,7 @@ itertools = { workspace = true } miden-block-prover = { git = "https://github.com/0xPolygonMiden/miden-base.git", branch = "next" } miden-lib = { workspace = true } miden-node-proto = { workspace = true } +miden-node-utils = { workspace = true } miden-objects = { workspace = true } miden-processor = { workspace = true } miden-tx = { workspace = true } From 270e3c6c8f075f5b5204bf76793bb3159dd91972 Mon Sep 17 00:00:00 2001 From: sergerad Date: Sat, 1 Mar 2025 19:55:02 +1300 Subject: [PATCH 19/20] Move i64 --- crates/utils/src/tracing/span_ext.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/crates/utils/src/tracing/span_ext.rs b/crates/utils/src/tracing/span_ext.rs index 77b359eda..4aed6c7a8 100644 --- a/crates/utils/src/tracing/span_ext.rs +++ b/crates/utils/src/tracing/span_ext.rs @@ -53,7 +53,7 @@ macro_rules! impl_int_to_value { )* }; } -impl_int_to_value!(u16, u32, i64); +impl_int_to_value!(u16, u32); /// Generates `impl ToValue` blocks for types that are `Into`. macro_rules! impl_to_value { @@ -67,7 +67,7 @@ macro_rules! impl_to_value { )* }; } -impl_to_value!(f64); +impl_to_value!(f64, i64); /// Utility functions based on [`tracing_opentelemetry::OpenTelemetrySpanExt`]. /// From 6091af1f41386598b90a85cfca5cf8aba2a5b199 Mon Sep 17 00:00:00 2001 From: sergerad Date: Sun, 2 Mar 2025 11:45:56 +1300 Subject: [PATCH 20/20] port u16 --- crates/utils/src/tracing/grpc.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/crates/utils/src/tracing/grpc.rs b/crates/utils/src/tracing/grpc.rs index ad2cc365a..6a5bb9508 100644 --- a/crates/utils/src/tracing/grpc.rs +++ b/crates/utils/src/tracing/grpc.rs @@ -77,7 +77,7 @@ fn add_otel_span_attributes(span: tracing::Span, request: &http::Request) span.set_attribute("server.address", host); } if let Some(host_port) = request.uri().port() { - span.set_attribute("server.port", host_port.as_str()); + span.set_attribute("server.port", host_port.as_u16()); } let remote_addr = request .extensions()