From bb3af254c740e13789642ff1394189b5c0612911 Mon Sep 17 00:00:00 2001 From: Ameer Ghani Date: Wed, 1 Nov 2023 13:24:27 -0500 Subject: [PATCH] Adopt `tracing` for logging (#607) --- Cargo.lock | 417 +++++++++++++++++++++++++++++++++++++++- Cargo.toml | 9 +- src/bin.rs | 18 +- src/config.rs | 72 +++++-- src/lib.rs | 1 + src/trace.rs | 228 ++++++++++++++++++++++ test-support/src/lib.rs | 9 +- 7 files changed, 730 insertions(+), 24 deletions(-) create mode 100644 src/trace.rs diff --git a/Cargo.lock b/Cargo.lock index 32aedf3a..7db69a9b 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2,6 +2,16 @@ # It is not intended for manual editing. version = 3 +[[package]] +name = "Inflector" +version = "0.11.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fe438c63458706e03479442743baae6c88256498e6431708f6dfc520a26515d3" +dependencies = [ + "lazy_static", + "regex", +] + [[package]] name = "addr2line" version = "0.21.0" @@ -440,6 +450,51 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "d468802bab17cbc0cc575e9b053f41e72aa36bfa6b7f55e3529ffa43161b97fa" +[[package]] +name = "axum" +version = "0.6.20" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3b829e4e32b91e643de6eafe82b1d90675f5874230191a4ffbc1b336dec4d6bf" +dependencies = [ + "async-trait", + "axum-core", + "bitflags 1.3.2", + "bytes", + "futures-util", + "http", + "http-body", + "hyper", + "itoa", + "matchit", + "memchr", + "mime", + "percent-encoding", + "pin-project-lite", + "rustversion", + "serde", + "sync_wrapper", + "tower", + "tower-layer", + "tower-service", +] + +[[package]] +name = "axum-core" +version = "0.3.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "759fa577a247914fd3f7f76d62972792636412fbfd634cd452f6a385a74d2d2c" +dependencies = [ + "async-trait", + "bytes", + "futures-util", + "http", + "http-body", + "mime", + "rustversion", + "tower-layer", + "tower-service", +] + [[package]] name = "backtrace" version = "0.3.69" @@ -824,6 +879,43 @@ dependencies = [ "crossbeam-utils", ] +[[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" @@ -1106,8 +1198,8 @@ dependencies = [ "async-lock", "async-session", "base64 0.21.5", + "console-subscriber", "email_address", - "env_logger", "fastrand 2.0.1", "futures-lite 2.0.0", "git-version", @@ -1133,6 +1225,11 @@ dependencies = [ "time", "tokio", "tracing", + "tracing-chrome", + "tracing-log 0.2.0", + "tracing-opentelemetry", + "tracing-stackdriver", + "tracing-subscriber", "trillium", "trillium-api", "trillium-caching-headers", @@ -1621,6 +1718,25 @@ dependencies = [ "subtle", ] +[[package]] +name = "h2" +version = "0.3.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "91fc23aa11be92976ef4729127f1a74adf36d8436f7816b185d18df956790833" +dependencies = [ + "bytes", + "fnv", + "futures-core", + "futures-sink", + "futures-util", + "http", + "indexmap 1.9.3", + "slab", + "tokio", + "tokio-util", + "tracing", +] + [[package]] name = "hashbrown" version = "0.12.3" @@ -1658,6 +1774,19 @@ dependencies = [ "hashbrown 0.14.2", ] +[[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 = "heck" version = "0.4.1" @@ -1765,6 +1894,17 @@ dependencies = [ "itoa", ] +[[package]] +name = "http-body" +version = "0.4.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d5f38f16d184e36f2408a55281cd658ecbd3ca05cce6d6510a176eca393e26d1" +dependencies = [ + "bytes", + "http", + "pin-project-lite", +] + [[package]] name = "httparse" version = "1.8.0" @@ -1783,6 +1923,42 @@ version = "2.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" +[[package]] +name = "hyper" +version = "0.14.27" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ffb1cfd654a8219eaef89881fdb3bb3b1cdc5fa75ded05d6933b2b382e395468" +dependencies = [ + "bytes", + "futures-channel", + "futures-core", + "futures-util", + "h2", + "http", + "http-body", + "httparse", + "httpdate", + "itoa", + "pin-project-lite", + "socket2 0.4.10", + "tokio", + "tower-service", + "tracing", + "want", +] + +[[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 = "iana-time-zone" version = "0.1.58" @@ -2025,6 +2201,12 @@ dependencies = [ "regex-automata 0.1.10", ] +[[package]] +name = "matchit" +version = "0.7.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0e7465ac9959cc2b1404e8e2367b43684a6d13790fe23056cc8c6c5a6b7bcb94" + [[package]] name = "md-5" version = "0.10.6" @@ -2326,6 +2508,8 @@ dependencies = [ "rand", "regex", "thiserror", + "tokio", + "tokio-stream", ] [[package]] @@ -2432,6 +2616,26 @@ version = "2.3.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9b2a4787296e9989611394c33f193f676704af1686e70b8f8033ab5ba9a35a94" +[[package]] +name = "pin-project" +version = "1.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fda4ed1c6c173e3fc7a83629421152e01d7b1f9b7f65fb301e490e8cfc656422" +dependencies = [ + "pin-project-internal", +] + +[[package]] +name = "pin-project-internal" +version = "1.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4359fd9c9171ec6e8c62926d6faaf553a8dc3f64e1507e76da7911b4f6a04405" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.38", +] + [[package]] name = "pin-project-lite" version = "0.2.13" @@ -2658,6 +2862,38 @@ dependencies = [ "thiserror", ] +[[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", + "proc-macro2", + "quote", + "syn 2.0.38", +] + +[[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" @@ -3023,6 +3259,12 @@ dependencies = [ "untrusted 0.9.0", ] +[[package]] +name = "rustversion" +version = "1.0.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7ffc183a10b4478d04cbbbfc96d0873219d962dd5accaff2ffbd4ceb7df837f4" + [[package]] name = "ryu" version = "1.0.15" @@ -3813,6 +4055,12 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "sync_wrapper" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2047c6ded9c721764247e62cd3b03c09ffc529b2ba5b10ec482ae507a4a70160" + [[package]] name = "tap" version = "1.0.1" @@ -3971,9 +4219,20 @@ dependencies = [ "signal-hook-registry", "socket2 0.5.5", "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" @@ -3996,6 +4255,20 @@ dependencies = [ "tokio", ] +[[package]] +name = "tokio-util" +version = "0.7.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5419f34732d9eb6ee4c3578b7989078579b7f039cbbb9ca2c4da015749371e15" +dependencies = [ + "bytes", + "futures-core", + "futures-sink", + "pin-project-lite", + "tokio", + "tracing", +] + [[package]] name = "toml" version = "0.5.11" @@ -4022,6 +4295,65 @@ 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.5", + "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" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b8fa9be0de6cf49e536ce1851f987bd21a43b771b09473c3549a6c853db37c1c" +dependencies = [ + "futures-core", + "futures-util", + "indexmap 1.9.3", + "pin-project", + "pin-project-lite", + "rand", + "slab", + "tokio", + "tokio-util", + "tower-layer", + "tower-service", + "tracing", +] + +[[package]] +name = "tower-layer" +version = "0.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c20c8dbed6283a09604c3e69b4b7eeb54e298b8a600d4d5ecb5ad39de609f1d0" + +[[package]] +name = "tower-service" +version = "0.3.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b6bc1c9ce2b5135ac7f93c72918fc37feb872bdc6a5533a8b85eb4b86bfdae52" + [[package]] name = "tracing" version = "0.1.40" @@ -4045,6 +4377,17 @@ dependencies = [ "syn 2.0.38", ] +[[package]] +name = "tracing-chrome" +version = "0.7.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "496b3cd5447f7ff527bbbf19b071ad542a000adf297d4127078b4dfdb931f41a" +dependencies = [ + "serde_json", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "tracing-core" version = "0.1.32" @@ -4066,6 +4409,58 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-opentelemetry" +version = "0.21.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "75327c6b667828ddc28f5e3f169036cb793c3f588d83bf0f262a7f062ffed3c8" +dependencies = [ + "once_cell", + "opentelemetry", + "opentelemetry_sdk", + "smallvec", + "tracing", + "tracing-core", + "tracing-log 0.1.4", + "tracing-subscriber", +] + +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-stackdriver" +version = "0.8.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "644201289b078e925ad49bfdeb7c0ced851d211462376d5154b13ce7be899afa" +dependencies = [ + "Inflector", + "serde", + "serde_json", + "thiserror", + "time", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "tracing-subscriber" version = "0.3.17" @@ -4076,12 +4471,15 @@ dependencies = [ "nu-ansi-term", "once_cell", "regex", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", - "tracing-log", + "tracing-log 0.1.4", + "tracing-serde", ] [[package]] @@ -4377,6 +4775,12 @@ dependencies = [ "trillium-server-common", ] +[[package]] +name = "try-lock" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3528ecfd12c466c6f163363caf2d02a71161dd5e1cc6ae7b34207ea2d42d81ed" + [[package]] name = "typenum" version = "1.17.0" @@ -4566,6 +4970,15 @@ version = "1.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f3c4517f54858c779bbcbf228f4fca63d121bf85fbecb2dc578cdf4a39395690" +[[package]] +name = "want" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bfa7760aed19e106de2c7c0b581b509f2f25d3dacaf737cb82ac61bc6d760b0e" +dependencies = [ + "try-lock", +] + [[package]] name = "wasi" version = "0.11.0+wasi-snapshot-preview1" diff --git a/Cargo.toml b/Cargo.toml index 4191d6f2..65f9d5e3 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -21,14 +21,14 @@ aes-gcm = "0.10.3" async-lock = "2.8.0" async-session = "3.0.0" base64 = "0.21.4" +console-subscriber = "0.2.0" email_address = "0.2.4" -env_logger = "0.10.0" fastrand = "2.0.1" futures-lite = "2.0.0" git-version = "0.3.5" janus_messages = "0.5.24" log = "0.4.20" -opentelemetry = { version = "0.20.0", features = ["metrics"] } +opentelemetry = { version = "0.20.0", features = ["metrics", "rt-tokio"] } opentelemetry-prometheus = { version = "0.13.0", features = [ "prometheus-encoding", ] } @@ -46,6 +46,11 @@ time = { version = "0.3.30", features = ["serde", "serde-well-known"] } tokio = { version = "1.33.0", features = ["full"] } tracing = "0.1.39" trillium = "0.2.11" +tracing-chrome = "0.7.1" +tracing-log = "0.2.0" +tracing-opentelemetry = "0.21.0" +tracing-stackdriver = "0.8.0" +tracing-subscriber = { version = "0.3.17", features = ["json", "env-filter", "std", "fmt"] } trillium-api = { version = "0.2.0-rc.4", default-features = false } trillium-caching-headers = "0.2.1" trillium-client = { version = "0.4.5", features = ["json"] } diff --git a/src/bin.rs b/src/bin.rs index 248bde55..9bd3cc90 100644 --- a/src/bin.rs +++ b/src/bin.rs @@ -1,12 +1,12 @@ -use divviup_api::{Config, DivviupApi, Queue}; - +use divviup_api::{ + trace::{install_trace_subscriber, traceconfig_handler}, + Config, DivviupApi, Queue, +}; use trillium_http::Stopper; use trillium_tokio::CloneCounterObserver; #[tokio::main] async fn main() { - env_logger::init(); - let config = match Config::from_env() { Ok(config) => config, Err(e) => { @@ -15,16 +15,20 @@ async fn main() { } }; + let (_guards, trace_reload_handle) = install_trace_subscriber(&config.trace_config()).unwrap(); + let stopper = Stopper::new(); let observer = CloneCounterObserver::default(); trillium_tokio::config() .without_signals() - .with_port(config.prometheus_port) - .with_host(&config.prometheus_host) + .with_socketaddr(config.monitoring_listen_address) .with_observer(observer.clone()) .with_stopper(stopper.clone()) - .spawn(divviup_api::telemetry::metrics_exporter().unwrap()); + .spawn(( + divviup_api::telemetry::metrics_exporter().unwrap(), + traceconfig_handler(trace_reload_handle), + )); let app = DivviupApi::new(config).await; diff --git a/src/config.rs b/src/config.rs index 75272960..300f7bea 100644 --- a/src/config.rs +++ b/src/config.rs @@ -1,7 +1,18 @@ -use crate::{handler::oauth2::Oauth2Config, Crypter}; +use crate::{ + handler::oauth2::Oauth2Config, + trace::{TokioConsoleConfig, TraceConfig}, + Crypter, +}; use base64::{engine::general_purpose::URL_SAFE_NO_PAD, Engine}; use email_address::EmailAddress; -use std::{collections::VecDeque, env::VarError, error::Error, str::FromStr}; +use std::{ + any::type_name, + collections::VecDeque, + env::{self, VarError}, + error::Error, + net::SocketAddr, + str::FromStr, +}; use thiserror::Error; use trillium_client::Client; use url::Url; @@ -22,9 +33,21 @@ pub struct Config { pub email_address: EmailAddress, pub postmark_token: String, pub postmark_url: Url, - pub prometheus_host: String, - pub prometheus_port: u16, + /// The address to listen on for prometheus metrics and tracing configuration. + pub monitoring_listen_address: SocketAddr, pub session_secrets: SessionSecrets, + /// See [`TraceConfig::use_test_writer`]. + pub trace_use_test_writer: bool, + /// See [`TraceConfig::force_json_writer`]. + pub trace_force_json_writer: bool, + /// See [`TraceConfig::stackdriver_json_output`]. + pub trace_stackdriver_json_output: bool, + /// See [`TraceConfig::chrome`]. + pub trace_chrome: bool, + /// See [`TokioConsoleConfig::enabled`]. + pub tokio_console_enabled: bool, + /// See [`TokioConsoleConfig::listen_address`]. + pub tokio_console_listen_address: SocketAddr, } #[derive(Debug, Error)] @@ -35,8 +58,11 @@ pub enum ConfigError { #[error("environment variable `{0}` found but was not unicode")] NotUnicode(&'static str), - #[error("The environment variable `{0}` was found, but was not a valid {1}:\n\t{2}\n")] - InvalidEnvVarFormat(&'static str, &'static str, Box), + #[error("environment variable `{0}` was found, but was not a valid {1}:\n\t{2}\n")] + InvalidEnvVarFormat(String, &'static str, Box), + + #[error(transparent)] + AddrParseError(#[from] std::net::AddrParseError), } fn var(name: &'static str) -> Result @@ -44,8 +70,8 @@ where T: FromStr, ::Err: Error + 'static, { - let format = std::any::type_name::(); - std::env::var(name) + let format = type_name::(); + env::var(name) .map_err(|error| match error { VarError::NotPresent => ConfigError::MissingEnvVar(name), VarError::NotUnicode(_) => ConfigError::NotUnicode(name), @@ -53,7 +79,7 @@ where .and_then(|input| { input .parse() - .map_err(|e| ConfigError::InvalidEnvVarFormat(name, format, Box::new(e))) + .map_err(|e| ConfigError::InvalidEnvVarFormat(name.into(), format, Box::new(e))) }) } @@ -101,9 +127,20 @@ impl Config { email_address: var("EMAIL_ADDRESS")?, postmark_token: var("POSTMARK_TOKEN")?, postmark_url: Url::parse(POSTMARK_URL).unwrap(), - prometheus_host: var_optional("OTEL_EXPORTER_PROMETHEUS_HOST", "localhost".into())?, - prometheus_port: var_optional("OTEL_EXPORTER_PROMETHEUS_PORT", 9464)?, + monitoring_listen_address: var_optional( + "MONITORING_LISTEN_ADDRESS", + "127.0.0.1:9464".parse().unwrap(), + )?, session_secrets: var("SESSION_SECRETS")?, + trace_use_test_writer: false, + trace_force_json_writer: var_optional("TRACE_FORCE_JSON_WRITER", false)?, + trace_stackdriver_json_output: var_optional("TRACE_STACKDRIVER_JSON_OUTPUT", false)?, + trace_chrome: var_optional("TRACE_CHROME", false)?, + tokio_console_enabled: var_optional("TOKIO_CONSOLE_ENABLED", false)?, + tokio_console_listen_address: var_optional( + "TOKIO_CONSOLE_LISTEN_ADDRESS", + "127.0.0.1:6669".parse().unwrap(), + )?, }) } @@ -119,6 +156,19 @@ impl Config { http_client: self.client.clone(), } } + + pub fn trace_config(&self) -> TraceConfig { + TraceConfig { + use_test_writer: self.trace_use_test_writer, + force_json_output: self.trace_force_json_writer, + stackdriver_json_output: self.trace_stackdriver_json_output, + tokio_console_config: TokioConsoleConfig { + enabled: self.tokio_console_enabled, + listen_address: Some(self.tokio_console_listen_address), + }, + chrome: self.trace_chrome, + } + } } impl AsRef for Config { diff --git a/src/lib.rs b/src/lib.rs index 695a3ef4..d3064a56 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -18,6 +18,7 @@ pub mod permissions; pub mod queue; mod routes; pub mod telemetry; +pub mod trace; mod user; pub use config::{Config, ConfigError}; diff --git a/src/trace.rs b/src/trace.rs new file mode 100644 index 00000000..da819c19 --- /dev/null +++ b/src/trace.rs @@ -0,0 +1,228 @@ +//! Configures a tracing subscriber for divviup-api. + +use serde::{Deserialize, Serialize}; +use std::{ + io::{stdout, IsTerminal}, + net::SocketAddr, + sync::Arc, +}; +use tracing::Level; +use tracing_chrome::{ChromeLayerBuilder, TraceStyle}; +use tracing_log::LogTracer; +use tracing_subscriber::{ + filter::FromEnvError, layer::SubscriberExt, reload, EnvFilter, Layer, Registry, +}; +use trillium::Handler; +use trillium_api::{api, State}; +use trillium_http::Status; +use trillium_router::Router; + +/// Errors from initializing trace subscriber. +#[derive(Debug, thiserror::Error)] +pub enum Error { + #[error("tracing error: {0}")] + SetGlobalTracingSubscriber(#[from] tracing::subscriber::SetGlobalDefaultError), + #[error("logging error: {0}")] + SetGlobalLogger(#[from] tracing_log::log_tracer::SetLoggerError), + #[error("bad log/trace filter: {0}")] + FromEnv(#[from] FromEnvError), + #[error("{0}")] + Other(&'static str), +} + +/// Configuration for the tracing subscriber. +#[derive(Clone, Copy, Debug, Default, PartialEq, Eq, Serialize, Deserialize)] +pub struct TraceConfig { + /// If true, uses a [`tracing_subscriber::fmt::TestWriter`] to capture trace + /// events when running tests + #[serde(default)] + pub use_test_writer: bool, + /// If true OR if stdout is not a tty, trace events are output in JSON + /// format by [`tracing_subscriber::fmt::format::Json`]. Otherwise, trace + /// events are output in pretty format by + /// [`tracing_subscriber::fmt::format::Pretty`]. + #[serde(default)] + pub force_json_output: bool, + /// If true, trace events are output in Google's Cloud Logging JSON format with + /// [`tracing_stackdriver`]. + #[serde(default)] + pub stackdriver_json_output: bool, + /// Configuration for tokio-console monitoring and debugging support. + /// (optional) + #[serde(default)] + pub tokio_console_config: TokioConsoleConfig, + /// Flag to write tracing spans and events to JSON files. This is compatible with Chrome's + /// trace viewer, available at `chrome://tracing`, and [Perfetto](https://ui.perfetto.dev). + #[serde(default)] + pub chrome: bool, +} + +/// Configuration related to tokio-console. +#[derive(Clone, Copy, Debug, Default, PartialEq, Eq, Serialize, Deserialize)] +pub struct TokioConsoleConfig { + /// If true, a tokio-console tracing subscriber is configured to monitor + /// the async runtime, and listen for TCP connections. (Requires building + /// with RUSTFLAGS="--cfg tokio_unstable") + #[serde(default)] + pub enabled: bool, + /// Specifies an alternate address and port for the subscriber's gRPC + /// server to listen on. If this is not present, it will use the value of + /// the environment variable TOKIO_CONSOLE_BIND, or, failing that, a + /// default of 127.0.0.1:6669. + #[serde(default)] + pub listen_address: Option, +} + +/// Create a base tracing layer with configuration used in all subscribers +fn base_layer() -> tracing_subscriber::fmt::Layer { + tracing_subscriber::fmt::layer() + .with_thread_ids(true) + .with_level(true) + .with_target(true) + .with_file(true) + .with_line_number(true) +} + +/// Construct a filter to be used with tracing-opentelemetry and tracing-chrome, based on the +/// contents of the `RUST_TRACE` environment variable. +fn make_trace_filter() -> Result { + EnvFilter::builder() + .with_default_directive(Level::INFO.into()) + .with_env_var("RUST_TRACE") + .from_env() +} + +pub type TraceReloadHandle = reload::Handle; + +/// Configures and installs a tracing subscriber, to capture events logged with [`tracing::info`] +/// and the like. Captured events are written to stdout, with formatting affected by the provided +/// [`TraceConfiguration`]. A handle to the stdout [`EnvFilter`] is provided, so that the filter +/// configuration can be altered later on at runtime. +pub fn install_trace_subscriber( + config: &TraceConfig, +) -> Result<(TraceGuards, TraceReloadHandle), Error> { + // If stdout is not a tty or if forced by config, output logs as JSON + // structures + let output_json = !stdout().is_terminal() || config.force_json_output; + + // Configure filters with RUST_LOG env var. Format discussed at + // https://docs.rs/tracing-subscriber/latest/tracing_subscriber/struct.EnvFilter.html + let (stdout_filter, stdout_filter_handle) = + reload::Layer::new(EnvFilter::builder().from_env()?); + + let mut layers = Vec::new(); + match ( + output_json, + config.use_test_writer, + config.stackdriver_json_output, + ) { + (true, false, false) => layers.push( + base_layer() + .json() + .with_current_span(false) + .with_filter(stdout_filter) + .boxed(), + ), + (false, false, false) => { + layers.push(base_layer().pretty().with_filter(stdout_filter).boxed()) + } + (_, true, false) => layers.push( + base_layer() + .pretty() + .with_test_writer() + .with_filter(stdout_filter) + .boxed(), + ), + (_, _, true) => layers.push( + tracing_stackdriver::layer() + .with_filter(stdout_filter) + .boxed(), + ), + } + + if config.tokio_console_config.enabled { + let console_filter = tracing_subscriber::filter::Targets::new() + .with_target("tokio", tracing::Level::TRACE) + .with_target("runtime", tracing::Level::TRACE); + + let mut builder = console_subscriber::ConsoleLayer::builder(); + builder = builder.with_default_env(); + if let Some(listen_address) = &config.tokio_console_config.listen_address { + builder = builder.server_addr(*listen_address); + } + layers.push(builder.spawn().with_filter(console_filter).boxed()); + } + + let mut chrome_guard = None; + if config.chrome { + let (layer, guard) = ChromeLayerBuilder::new() + .trace_style(TraceStyle::Async) + .include_args(true) + .build(); + chrome_guard = Some(guard); + layers.push(layer.with_filter(make_trace_filter()?).boxed()); + } + + let subscriber = Registry::default().with(layers); + + tracing::subscriber::set_global_default(subscriber)?; + + // Install a logger that converts logs into tracing events + LogTracer::init()?; + + Ok(( + TraceGuards { + _chrome_guard: chrome_guard, + }, + stdout_filter_handle, + )) +} + +#[allow(missing_debug_implementations)] +pub struct TraceGuards { + _chrome_guard: Option, +} + +pub fn traceconfig_handler(trace_reload_handle: TraceReloadHandle) -> impl Handler { + ( + State(Arc::new(trace_reload_handle)), + Router::new() + .get("/traceconfig", api(get_traceconfig)) + .put("/traceconfig", api(put_traceconfig)), + ) +} + +async fn get_traceconfig( + conn: &mut trillium::Conn, + State(trace_reload_handle): State>, +) -> Result { + trace_reload_handle + .with_current(|trace_filter| trace_filter.to_string()) + .map_err(|err| { + conn.set_body(format!("failed to get current filter: {err}")); + Status::InternalServerError + }) +} + +/// Allows modifying the runtime tracing filter. Accepts a request whose body is a valid tracing +/// filter. Responds with the updated filter. See [`EnvFilter::try_new`] for details on the accepted +/// format. +async fn put_traceconfig( + conn: &mut trillium::Conn, + (State(trace_reload_handle), request): (State>, String), +) -> Result { + let new_filter = EnvFilter::try_new(request).map_err(|err| { + conn.set_body(format!("invalid filter: {err}")); + Status::BadRequest + })?; + trace_reload_handle.reload(new_filter).map_err(|err| { + conn.set_body(format!("failed to update filter: {err}")); + Status::InternalServerError + })?; + trace_reload_handle + .with_current(|trace_filter| trace_filter.to_string()) + .map_err(|err| { + conn.set_body(format!("failed to get current filter: {err}")); + Status::InternalServerError + }) +} diff --git a/test-support/src/lib.rs b/test-support/src/lib.rs index b10cb07b..0a6d5eda 100644 --- a/test-support/src/lib.rs +++ b/test-support/src/lib.rs @@ -87,13 +87,18 @@ pub fn config(api_mocks: impl Handler) -> Config { auth_client_id: "client id".into(), auth_client_secret: "client secret".into(), auth_audience: "aud".into(), - prometheus_host: "localhost".into(), - prometheus_port: 9464, + monitoring_listen_address: "127.0.0.1:9464".parse().unwrap(), postmark_token: "-".into(), email_address: "test@example.test".parse().unwrap(), postmark_url: POSTMARK_URL.parse().unwrap(), client: Client::new(trillium_testing::connector(api_mocks)), crypter: Crypter::from(Crypter::generate_key()), + trace_use_test_writer: true, + trace_force_json_writer: false, + trace_stackdriver_json_output: false, + trace_chrome: false, + tokio_console_enabled: false, + tokio_console_listen_address: "127.0.0.1:6669".parse().unwrap(), } }