From 8be3d0d9b01dc49d310247e31c5e7227b05c5a60 Mon Sep 17 00:00:00 2001 From: Felix Leupold Date: Fri, 6 Oct 2023 14:38:54 +0200 Subject: [PATCH] Add support for connecting tokio-console to binaries (#1915) # Description If compiled with `RUSTFLAGS="--cfg tokio_unstable"` we can now attact [tokio-console](https://github.com/tokio-rs/console) to our binaries which can help us to debug issues with debug issues with our async code # Changes - Adds https://github.com/tokio-rs/console/tree/main/console-subscriber as a dependency to our observe crate - Conditionally registers the console subscriber as an extra layer in our tracing subscriber registry (this required some rewriting of the existing layering) Docs: https://docs.rs/console-subscriber/latest/console_subscriber/#adding-the-console-subscriber ## How to test ``` RUSTFLAGS="--cfg tokio_unstable" cargo run --bin autopilot ``` In a separate console ``` cargo install --locked tokio-console tokio-console ``` and observe tokio runtime information image --- Cargo.lock | 153 ++++++++++++++++++++++++++++++++++ README.md | 11 +++ crates/observe/Cargo.toml | 1 + crates/observe/src/tracing.rs | 41 +++++---- 4 files changed, 192 insertions(+), 14 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 0c0f394590..b313088b74 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1267,6 +1267,43 @@ version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "acbf1af155f9b9ef647e42cdc158db4b64a1b61f743629225fde6f3e0be2a7c7" +[[package]] +name = "console-api" +version = "0.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fd326812b3fd01da5bb1af7d340d0d555fd3d4b641e7f1dfcf5962a902952787" +dependencies = [ + "futures-core", + "prost", + "prost-types", + "tonic", + "tracing-core", +] + +[[package]] +name = "console-subscriber" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7481d4c57092cd1c19dd541b92bdce883de840df30aa5d03fd48a3935c01842e" +dependencies = [ + "console-api", + "crossbeam-channel", + "crossbeam-utils", + "futures-task", + "hdrhistogram", + "humantime", + "prost-types", + "serde", + "serde_json", + "thread_local", + "tokio", + "tokio-stream", + "tonic", + "tracing", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "const-oid" version = "0.9.5" @@ -1399,6 +1436,16 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a33c2bf77f2df06183c3aa30d1e96c0695a313d4f9c453cc3762a6db39f99200" +dependencies = [ + "cfg-if", + "crossbeam-utils", +] + [[package]] name = "crossbeam-queue" version = "0.3.8" @@ -2240,6 +2287,19 @@ dependencies = [ "hashbrown 0.14.0", ] +[[package]] +name = "hdrhistogram" +version = "7.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7f19b9f54f7c7f55e31401bb647626ce0cf0f67b0004982ce815b3ee72a02aa8" +dependencies = [ + "base64 0.13.1", + "byteorder", + "flate2", + "nom", + "num-traits", +] + [[package]] name = "headers" version = "0.3.8" @@ -2368,6 +2428,12 @@ version = "1.0.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c4a1e36c821dbe04574f602848a19f742f4fb3c98d40449f11bcad18d6b17421" +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "hyper" version = "0.14.27" @@ -2423,6 +2489,18 @@ dependencies = [ "tokio-rustls 0.24.1", ] +[[package]] +name = "hyper-timeout" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbb958482e8c7be4bc3cf272a766a2b0bf1a6755e7a6ae777f017a31d11b13b1" +dependencies = [ + "hyper", + "pin-project-lite", + "tokio", + "tokio-io-timeout", +] + [[package]] name = "hyper-tls" version = "0.5.0" @@ -3034,6 +3112,7 @@ name = "observe" version = "0.1.0" dependencies = [ "atty", + "console-subscriber", "once_cell", "prometheus", "prometheus-metric-storage", @@ -3404,6 +3483,38 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "prost" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f4fdd22f3b9c31b53c060df4a0613a1c7f062d4115a2b984dd15b1858f7e340d" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "265baba7fabd416cf5078179f7d2cbeca4ce7a9041111900675ea7c4cb8a4c32" +dependencies = [ + "anyhow", + "itertools 0.11.0", + "proc-macro2", + "quote", + "syn 2.0.28", +] + +[[package]] +name = "prost-types" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e081b29f63d83a4bc75cfc9f3fe424f9156cf92d8a4f0c9407cce9a1b67327cf" +dependencies = [ + "prost", +] + [[package]] name = "protobuf" version = "2.28.0" @@ -4623,9 +4734,20 @@ dependencies = [ "signal-hook-registry", "socket2 0.5.3", "tokio-macros", + "tracing", "windows-sys", ] +[[package]] +name = "tokio-io-timeout" +version = "1.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "30b74022ada614a1b4834de765f9bb43877f910cc8ce4be40e89042c9223a8bf" +dependencies = [ + "pin-project-lite", + "tokio", +] + [[package]] name = "tokio-macros" version = "2.1.0" @@ -4743,6 +4865,33 @@ dependencies = [ "winnow", ] +[[package]] +name = "tonic" +version = "0.10.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d560933a0de61cf715926b9cac824d4c883c2c43142f787595e48280c40a1d0e" +dependencies = [ + "async-stream", + "async-trait", + "axum", + "base64 0.21.2", + "bytes", + "h2", + "http", + "http-body", + "hyper", + "hyper-timeout", + "percent-encoding", + "pin-project", + "prost", + "tokio", + "tokio-stream", + "tower", + "tower-layer", + "tower-service", + "tracing", +] + [[package]] name = "tower" version = "0.4.13" @@ -4751,9 +4900,13 @@ checksum = "b8fa9be0de6cf49e536ce1851f987bd21a43b771b09473c3549a6c853db37c1c" dependencies = [ "futures-core", "futures-util", + "indexmap 1.9.3", "pin-project", "pin-project-lite", + "rand", + "slab", "tokio", + "tokio-util 0.7.8", "tower-layer", "tower-service", "tracing", diff --git a/README.md b/README.md index f8cf329c9f..30308c2534 100644 --- a/README.md +++ b/README.md @@ -162,6 +162,17 @@ ANVIL_IP_ADDR=0.0.0.0 anvil \ --timestamp 1577836800 ``` +### Profiling + +In order to attach [tokio-console](https://github.com/tokio-rs/console) to the running process, compile the binary using `RUSTFLAGS="--cfg tokio_unstable"`. + +Then in another shell, simply run + +``` +cargo install --locked tokio-console +tokio-console +``` + ## Running the Services Locally ### Prerequisites diff --git a/crates/observe/Cargo.toml b/crates/observe/Cargo.toml index 6fa6bb561f..45a5830011 100644 --- a/crates/observe/Cargo.toml +++ b/crates/observe/Cargo.toml @@ -7,6 +7,7 @@ license = "MIT OR Apache-2.0" [dependencies] atty = "0.2" +console-subscriber = "0.2.0" once_cell = { workspace = true } prometheus = { workspace = true } prometheus-metric-storage = { workspace = true } diff --git a/crates/observe/src/tracing.rs b/crates/observe/src/tracing.rs index e2c8ce6f66..248799c400 100644 --- a/crates/observe/src/tracing.rs +++ b/crates/observe/src/tracing.rs @@ -2,7 +2,13 @@ use { std::{panic::PanicInfo, sync::Once}, time::macros::format_description, tracing::level_filters::LevelFilter, - tracing_subscriber::fmt::{time::UtcTime, writer::MakeWriterExt as _}, + tracing_subscriber::{ + fmt::{time::UtcTime, writer::MakeWriterExt as _}, + prelude::*, + util::SubscriberInitExt, + EnvFilter, + Layer, + }, }; /// Initializes tracing setup that is shared between the binaries. @@ -25,22 +31,29 @@ pub fn initialize_reentrant(env_filter: &str) { } fn set_tracing_subscriber(env_filter: &str, stderr_threshold: LevelFilter) { - // This is what kibana uses to separate multi line log messages. - let subscriber_builder = tracing_subscriber::fmt::fmt() + let fmt_layer = tracing_subscriber::fmt::layer() + .with_writer( + std::io::stdout + .with_min_level( + stderr_threshold + .into_level() + .unwrap_or(tracing::Level::ERROR), + ) + .or_else(std::io::stderr), + ) .with_timer(UtcTime::new(format_description!( + // This is what kibana uses to separate multi line log messages. "[year]-[month]-[day]T[hour]:[minute]:[second].[subsecond digits:3]Z" ))) - .with_env_filter(env_filter) - .with_ansi(atty::is(atty::Stream::Stdout)); - match stderr_threshold.into_level() { - Some(threshold) => subscriber_builder - .with_writer( - std::io::stderr - .with_max_level(threshold) - .or_else(std::io::stdout), - ) - .init(), - None => subscriber_builder.init(), + .with_ansi(atty::is(atty::Stream::Stdout)) + .with_filter::(env_filter.into()); + + let registry = tracing_subscriber::registry().with(fmt_layer); + if cfg!(tokio_unstable) { + // Start with tokio_console subscriber + registry.with(console_subscriber::spawn()).init(); + } else { + registry.init() } }