From e6249c58e92f7693321a5403ce6770077b35bb11 Mon Sep 17 00:00:00 2001 From: Piotr Orzechowski Date: Tue, 20 Feb 2024 19:02:47 +0100 Subject: [PATCH] Add telemetry --- Cargo.lock | 231 ++++++++++++++++++++++++++++++++++++ Cargo.toml | 8 ++ src/configuration.rs | 22 ++-- src/lib.rs | 1 + src/main.rs | 21 +++- src/routes/subscriptions.rs | 36 ++++-- src/startup.rs | 17 ++- src/telemetry.rs | 69 +++++++++++ tests/subscriptions.rs | 4 +- tests/util/mod.rs | 34 ++++-- 10 files changed, 407 insertions(+), 36 deletions(-) create mode 100644 src/telemetry.rs diff --git a/Cargo.lock b/Cargo.lock index 25f1ac5..6c003b5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -30,6 +30,15 @@ dependencies = [ "zerocopy", ] +[[package]] +name = "aho-corasick" +version = "1.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b2969dcb958b36655471fc61f7e416fa76033bdd4bfed0678d8fee1e2d07a1f0" +dependencies = [ + "memchr", +] + [[package]] name = "allocator-api2" version = "0.2.16" @@ -571,6 +580,16 @@ dependencies = [ "version_check", ] +[[package]] +name = "gethostname" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c1ebd34e35c46e00bb73e81363248d627782724609fe1b6396f553f68fe3862e" +dependencies = [ + "libc", + "winapi", +] + [[package]] name = "getrandom" version = "0.2.12" @@ -960,6 +979,15 @@ version = "0.4.20" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b5e6163cb8c49088c2c36f57875e58ccd8c87c7427f7fbd50ea6710b2f3f2e8f" +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "matchit" version = "0.7.3" @@ -1053,6 +1081,16 @@ dependencies = [ "minimal-lexical", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + [[package]] name = "num-bigint-dig" version = "0.8.4" @@ -1185,6 +1223,12 @@ dependencies = [ "hashbrown 0.13.2", ] +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + [[package]] name = "parking_lot" version = "0.12.1" @@ -1408,6 +1452,50 @@ dependencies = [ "bitflags 1.3.2", ] +[[package]] +name = "regex" +version = "1.10.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b62dbe01f0b06f9d8dc7d49e05a0785f153b00b2c227856282f671e0318c9b15" +dependencies = [ + "aho-corasick", + "memchr", + "regex-automata 0.4.5", + "regex-syntax 0.8.2", +] + +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", +] + +[[package]] +name = "regex-automata" +version = "0.4.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5bb987efffd3c6d0d8f5f89510bb458559eab11e4f869acb20bf845e016259cd" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax 0.8.2", +] + +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + +[[package]] +name = "regex-syntax" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c08c74e62047bb2de4ff487b251e4a92e24f48745648451635cec7d591162d9f" + [[package]] name = "reqwest" version = "0.11.24" @@ -1545,6 +1633,16 @@ version = "1.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "94143f37725109f92c262ed2cf5e59bce7498c01bcc1502d7b9afe439a4e9f49" +[[package]] +name = "secrecy" +version = "0.8.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9bd1c54ea06cfd2f6b63219704de0b9b4f72dcc2b8fdef820be6cd799780e91e" +dependencies = [ + "serde", + "zeroize", +] + [[package]] name = "security-framework" version = "2.9.2" @@ -1652,6 +1750,15 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "signature" version = "2.2.0" @@ -2027,6 +2134,16 @@ dependencies = [ "syn 2.0.48", ] +[[package]] +name = "thread_local" +version = "1.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3fdd6f064ccff2d6567adcb3873ca630700f00b5ad3f060c25b5dcfd9a4ce152" +dependencies = [ + "cfg-if", + "once_cell", +] + [[package]] name = "time" version = "0.3.34" @@ -2195,6 +2312,25 @@ dependencies = [ "tracing", ] +[[package]] +name = "tower-http" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0da193277a4e2c33e59e09b5861580c33dd0a637c3883d0fa74ba40c0374af2e" +dependencies = [ + "bitflags 2.4.2", + "bytes", + "http 1.0.0", + "http-body 1.0.0", + "http-body-util", + "pin-project-lite", + "tower", + "tower-layer", + "tower-service", + "tracing", + "uuid", +] + [[package]] name = "tower-layer" version = "0.3.2" @@ -2230,6 +2366,24 @@ dependencies = [ "syn 2.0.48", ] +[[package]] +name = "tracing-bunyan-formatter" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b5c266b9ac83dedf0e0385ad78514949e6d89491269e7065bee51d2bb8ec7373" +dependencies = [ + "ahash", + "gethostname", + "log", + "serde", + "serde_json", + "time", + "tracing", + "tracing-core", + "tracing-log 0.1.4", + "tracing-subscriber", +] + [[package]] name = "tracing-core" version = "0.1.32" @@ -2237,6 +2391,47 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f751112709b4e791d8ce53e32c4ed2d353565a795ce84da2285393f41557bdf2" +dependencies = [ + "log", + "once_cell", + "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-subscriber" +version = "0.3.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log 0.2.0", ] [[package]] @@ -2316,6 +2511,12 @@ dependencies = [ "getrandom", ] +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "vcpkg" version = "0.2.15" @@ -2425,6 +2626,28 @@ version = "1.4.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "22fc3756b8a9133049b26c7f61ab35416c130e8c09b660f5b3958b446f52cc50" +[[package]] +name = "winapi" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419" +dependencies = [ + "winapi-i686-pc-windows-gnu", + "winapi-x86_64-pc-windows-gnu", +] + +[[package]] +name = "winapi-i686-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" + +[[package]] +name = "winapi-x86_64-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" + [[package]] name = "windows-sys" version = "0.48.0" @@ -2591,11 +2814,19 @@ version = "0.1.0" dependencies = [ "axum", "config", + "once_cell", "reqwest", + "secrecy", "serde", "sqlx", "time", "tokio", + "tower", + "tower-http", + "tracing", + "tracing-bunyan-formatter", + "tracing-log 0.2.0", + "tracing-subscriber", "uuid", ] diff --git a/Cargo.toml b/Cargo.toml index ef7d42c..8c7a93b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -15,10 +15,18 @@ name = "zero2prod" [dependencies] axum = "0.7.4" config = "0.14.0" +once_cell = "1.19.0" +secrecy = { version = "0.8.0", features = ["serde"] } serde = { version = "1.0.196", features = ["derive"] } sqlx = { version = "0.7.3", features = ["macros", "migrate", "postgres", "time", "runtime-tokio", "tls-native-tls", "uuid"], default-features = false } time = { version = "0.3.34", features = ["macros", "serde"] } tokio = { version = "1.36.0", features = ["macros", "rt-multi-thread"] } +tower = "0.4.13" +tower-http = { version = "0.5.1", features = ["request-id", "trace", "util"] } +tracing = "0.1.40" +tracing-bunyan-formatter = "0.3.9" +tracing-log = "0.2.0" +tracing-subscriber = { version = "0.3.18", features = ["env-filter"] } uuid = { version = "1.7.0", features = ["v4"] } [dev-dependencies] diff --git a/src/configuration.rs b/src/configuration.rs index 7ecb004..b38c5f8 100644 --- a/src/configuration.rs +++ b/src/configuration.rs @@ -1,3 +1,4 @@ +use secrecy::{ExposeSecret, Secret}; use serde::Deserialize; #[derive(Deserialize)] @@ -12,24 +13,27 @@ pub struct DatabaseSettings { pub host: String, pub port: u16, pub username: String, - pub password: String, + pub password: Secret, pub database_name: String, } impl DatabaseSettings { - pub fn connection_string(&self) -> String { - format!( + pub fn connection_string(&self) -> Secret { + Secret::new(format!( "{}/{}", - self.connection_string_without_db(), + self.connection_string_without_db().expose_secret(), self.database_name - ) + )) } - pub fn connection_string_without_db(&self) -> String { - format!( + pub fn connection_string_without_db(&self) -> Secret { + Secret::new(format!( "postgres://{}:{}@{}:{}", - self.username, self.password, self.host, self.port - ) + self.username, + self.password.expose_secret(), + self.host, + self.port + )) } } diff --git a/src/lib.rs b/src/lib.rs index 5d1dce7..9079ef9 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1,3 +1,4 @@ pub mod configuration; pub mod routes; pub mod startup; +pub mod telemetry; diff --git a/src/main.rs b/src/main.rs index f01fb4e..83b35ff 100644 --- a/src/main.rs +++ b/src/main.rs @@ -1,16 +1,27 @@ +use secrecy::ExposeSecret; use sqlx::PgPool; use tokio::net::TcpListener; -use zero2prod::{configuration::get_configuration, startup::run}; +use zero2prod::{ + configuration::get_configuration, + startup::run, + telemetry::{get_subscriber, init_subscriber}, +}; #[tokio::main] async fn main() -> Result<(), std::io::Error> { - let config = get_configuration().expect("Failed to read configuration."); + let subscriber = get_subscriber("zero2prod".into(), "info".into(), std::io::stdout); + init_subscriber(subscriber); + + let config = get_configuration().expect("Failed to read configuration"); let address = format!("{}:{}", config.application_host, config.application_port); + let listener = TcpListener::bind(address) .await - .expect("Failed to open listener."); - let pool = PgPool::connect(&config.database.connection_string()) + .expect("Failed to open listener"); + + let pool = PgPool::connect(&config.database.connection_string().expose_secret()) .await - .expect("Failed to connect to Postgres."); + .expect("Failed to connect to Postgres"); + run(listener, pool).await } diff --git a/src/routes/subscriptions.rs b/src/routes/subscriptions.rs index cb3487f..6ebf633 100644 --- a/src/routes/subscriptions.rs +++ b/src/routes/subscriptions.rs @@ -8,8 +8,27 @@ pub fn router() -> Router { Router::new().route("/subscriptions", post(subscribe)) } +#[tracing::instrument( + name = "Adding new subscriber", + skip(form, db_pool), + fields( + subscriber_email = %form.email, + subscriber_name = %form.name + ) +)] async fn subscribe(State(db_pool): State, Form(form): Form) -> StatusCode { - match sqlx::query!( + match insert_subscriber(&form, &db_pool).await { + Ok(_) => StatusCode::OK, + Err(_) => StatusCode::INTERNAL_SERVER_ERROR, + } +} + +#[tracing::instrument( + name = "Saving new subscriber details in the database", + skip(form, db_pool) +)] +pub async fn insert_subscriber(form: &Subscription, db_pool: &PgPool) -> Result<(), sqlx::Error> { + sqlx::query!( r#" INSERT INTO subscriptions (id, email, name, subscribed_at) VALUES ($1, $2, $3, $4) @@ -19,15 +38,14 @@ async fn subscribe(State(db_pool): State, Form(form): Form form.name, OffsetDateTime::now_utc(), ) - .execute(&db_pool) + .execute(db_pool) .await - { - Ok(_) => StatusCode::OK, - Err(e) => { - println!("Failed to execute query: {}", e); - StatusCode::INTERNAL_SERVER_ERROR - } - } + .map_err(|e| { + tracing::error!("Failed to execute query: {e:?}"); + e + })?; + + Ok(()) } #[derive(Deserialize)] diff --git a/src/startup.rs b/src/startup.rs index ff02b85..9ccfb40 100644 --- a/src/startup.rs +++ b/src/startup.rs @@ -1,14 +1,25 @@ -use crate::routes::{health_check, subscriptions}; +use crate::{ + routes::{health_check, subscriptions}, + telemetry::{request_span, RequestUuid}, +}; use axum::Router; use sqlx::PgPool; use tokio::net::TcpListener; +use tower::ServiceBuilder; +use tower_http::{trace::TraceLayer, ServiceBuilderExt}; pub async fn run(listener: TcpListener, db_pool: PgPool) -> Result<(), std::io::Error> { let app = Router::new() .merge(health_check::router()) .merge(subscriptions::router()) - .with_state(db_pool); + .with_state(db_pool) + .layer( + ServiceBuilder::new() + .set_x_request_id(RequestUuid) + .layer(TraceLayer::new_for_http().make_span_with(request_span)) + .propagate_x_request_id(), + ); - println!("Listening on {}", listener.local_addr()?); + tracing::info!("Listening on {}", listener.local_addr()?); axum::serve(listener, app).await } diff --git a/src/telemetry.rs b/src/telemetry.rs new file mode 100644 index 0000000..d760aa6 --- /dev/null +++ b/src/telemetry.rs @@ -0,0 +1,69 @@ +use axum::{ + body::Body, + http::{HeaderName, HeaderValue, Request}, +}; +use tower_http::request_id::{MakeRequestId, RequestId}; +use tracing::{subscriber::set_global_default, Span, Subscriber}; +use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer}; +use tracing_log::LogTracer; +use tracing_subscriber::{fmt::MakeWriter, layer::SubscriberExt, Registry}; +use uuid::Uuid; + +pub fn get_subscriber( + name: String, + default_env_filter: String, + sink: Sink, +) -> impl Subscriber + Send + Sync +where + Sink: for<'a> MakeWriter<'a> + Send + Sync + 'static, +{ + Registry::default() + .with( + tracing_subscriber::EnvFilter::try_from_default_env() + .unwrap_or_else(|_| default_env_filter.into()), + ) + .with(JsonStorageLayer) + .with(BunyanFormattingLayer::new(name.into(), sink)) +} + +pub fn init_subscriber(subscriber: impl Subscriber + Send + Sync) { + LogTracer::init().expect("Failed to set logger"); + set_global_default(subscriber).expect("Failed to set subscriber"); +} + +#[derive(Clone)] +pub struct RequestUuid; + +impl MakeRequestId for RequestUuid { + fn make_request_id(&mut self, _: &Request) -> Option { + match HeaderValue::from_str(&Uuid::new_v4().to_string()) { + Ok(value) => Some(RequestId::new(value)), + Err(e) => { + tracing::warn!("Failed to create request id header value: {e:?}"); + None + } + } + } +} + +pub fn request_span(request: &Request) -> Span { + let request_id = request + .headers() + .get(HeaderName::from_static("x-request-id")) + .and_then(|value| match value.to_str() { + Ok(value) => Some(value), + Err(e) => { + tracing::error!("Failed to convert x-request-id to str: {e:?}"); + None + } + }) + .unwrap_or("not available"); + + tracing::info_span!( + "Request", + request_id = request_id, + method = request.method().to_string(), + path = request.uri().path(), + query = request.uri().query() + ) +} diff --git a/tests/subscriptions.rs b/tests/subscriptions.rs index f99b832..e2e4f96 100644 --- a/tests/subscriptions.rs +++ b/tests/subscriptions.rs @@ -22,7 +22,7 @@ async fn subscribe_returns_a_200_for_valid_form_data() { let saved = sqlx::query!("SELECT name, email FROM subscriptions") .fetch_one(&app.db_pool) .await - .expect("Failed to fetch saved subscription."); + .expect("Failed to fetch saved subscription"); assert_eq!(saved.name, "Imię Nazwisko"); assert_eq!(saved.email, "imię.nazwisko@example.com"); } @@ -59,7 +59,7 @@ async fn subscribe_returns_a_400_when_data_is_missing() { let saved = sqlx::query!("SELECT name, email FROM subscriptions") .fetch_optional(&app.db_pool) .await - .expect("Failed to fetch unsaved subscription."); + .expect("Failed to fetch unsaved subscription"); assert!(saved.is_none()); } } diff --git a/tests/util/mod.rs b/tests/util/mod.rs index f9c957e..017d027 100644 --- a/tests/util/mod.rs +++ b/tests/util/mod.rs @@ -1,18 +1,35 @@ +use once_cell::sync::Lazy; +use secrecy::ExposeSecret; use sqlx::{Connection, Executor, PgConnection, PgPool}; use std::net::SocketAddr; use uuid::Uuid; use zero2prod::{ configuration::{get_configuration, DatabaseSettings}, startup::run, + telemetry::{get_subscriber, init_subscriber}, }; +static TRACING: Lazy<()> = Lazy::new(|| { + let name = "test"; + let default_env_filter = "info"; + if std::env::var("TEST_LOG").is_ok() { + let subscriber = get_subscriber(name.into(), default_env_filter.into(), std::io::stdout); + init_subscriber(subscriber); + } else { + let subscriber = get_subscriber(name.into(), default_env_filter.into(), std::io::sink); + init_subscriber(subscriber); + } +}); + pub struct TestApp { pub address: SocketAddr, pub db_pool: PgPool, } pub async fn spawn_app() -> TestApp { - let mut config = get_configuration().expect("Failed to read configuration."); + Lazy::force(&TRACING); + + let mut config = get_configuration().expect("Failed to read configuration"); config.database.database_name = Uuid::new_v4().to_string(); let listener = tokio::net::TcpListener::bind("localhost:0") @@ -37,22 +54,23 @@ pub fn url(addr: SocketAddr, endpoint: &str) -> String { } async fn configure_database(configuration: &DatabaseSettings) -> PgPool { - let mut conn = PgConnection::connect(&configuration.connection_string_without_db()) - .await - .expect("Failed to connect to Postgres."); + let mut conn = + PgConnection::connect(&configuration.connection_string_without_db().expose_secret()) + .await + .expect("Failed to connect to Postgres"); conn.execute(format!(r#"CREATE DATABASE "{}";"#, configuration.database_name).as_str()) .await - .expect("Failed to create database."); + .expect("Failed to create database"); - let pool = PgPool::connect(&configuration.connection_string()) + let pool = PgPool::connect(&configuration.connection_string().expose_secret()) .await - .expect("Failed to connect to Postgres."); + .expect("Failed to connect to Postgres"); sqlx::migrate!("./migrations") .run(&pool) .await - .expect("Failed to migrate the database."); + .expect("Failed to migrate database"); pool }