From e0aea1517b8efba869eafc0b14479345ad528977 Mon Sep 17 00:00:00 2001 From: Conrad Ludgate Date: Wed, 20 Apr 2022 20:56:26 +0100 Subject: [PATCH 1/3] enable tracing on server --- Cargo.lock | 65 +++++++++++++++++++++++++++- Cargo.toml | 11 +++++ atuin-server/Cargo.toml | 2 +- atuin-server/src/database.rs | 1 + atuin-server/src/handlers/history.rs | 1 + atuin-server/src/handlers/user.rs | 1 + atuin-server/src/lib.rs | 3 -- src/command/server.rs | 7 ++- 8 files changed, 85 insertions(+), 6 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index e25c51a171d..7889e48553a 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -22,6 +22,15 @@ dependencies = [ "memchr", ] +[[package]] +name = "ansi_term" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2" +dependencies = [ + "winapi", +] + [[package]] name = "async-trait" version = "0.1.53" @@ -82,6 +91,7 @@ dependencies = [ "tabwriter", "termion", "tokio", + "tracing-subscriber", "tui", "unicode-width", ] @@ -149,7 +159,6 @@ dependencies = [ "eyre", "fs-err", "http", - "log", "rand 0.8.5", "rust-crypto", "serde", @@ -158,6 +167,7 @@ dependencies = [ "sodiumoxide", "sqlx", "tokio", + "tracing", "uuid", "whoami", ] @@ -1167,6 +1177,15 @@ version = "1.0.2" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3e2e65a1a2e43cfcb47a895c4c8b10d1f4a61097f9f254f183aee60cad9c651d" +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata", +] + [[package]] name = "matches" version = "0.1.9" @@ -1725,6 +1744,9 @@ name = "regex-automata" version = "0.1.10" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax", +] [[package]] name = "regex-syntax" @@ -2004,6 +2026,15 @@ dependencies = [ "digest 0.10.3", ] +[[package]] +name = "sharded-slab" +version = "0.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "900fba806f70c630b0a382d0d825e17a0f19fcd059a2ade1ff237bcddf446b31" +dependencies = [ + "lazy_static", +] + [[package]] name = "shellexpand" version = "2.1.0" @@ -2290,6 +2321,15 @@ dependencies = [ "syn", ] +[[package]] +name = "thread_local" +version = "1.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5516c27b78311c50bf42c071425c560ac799b11c30b31f87e3081965fe5e0180" +dependencies = [ + "once_cell", +] + [[package]] name = "time" version = "0.1.43" @@ -2481,6 +2521,23 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "90442985ee2f57c9e1b548ee72ae842f4a9a20e3f417cc38dbc5dc684d9bb4ee" dependencies = [ "lazy_static", + "valuable", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.11" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "4bc28f93baff38037f64e6f43d34cfa1605f27a49c34e8a04c5e78b0babf2596" +dependencies = [ + "ansi_term", + "lazy_static", + "matchers", + "regex", + "sharded-slab", + "thread_local", + "tracing", + "tracing-core", ] [[package]] @@ -2586,6 +2643,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" diff --git a/Cargo.toml b/Cargo.toml index b39a4f59f81..b860e40a6f9 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -59,6 +59,17 @@ clap = { version = "3.1.10", features = ["derive"] } clap_complete = "3.1.1" fs-err = "2.7" + +[dependencies.tracing-subscriber] +version = "0.3" +default-features = false +features = [ + "ansi", + "fmt", + "registry", + "env-filter", +] + [profile.release] lto = "fat" codegen-units = 1 diff --git a/atuin-server/Cargo.toml b/atuin-server/Cargo.toml index 871a31f7a31..92f4bd03b59 100644 --- a/atuin-server/Cargo.toml +++ b/atuin-server/Cargo.toml @@ -11,7 +11,7 @@ repository = "https://github.com/ellie/atuin" [dependencies] atuin-common = { path = "../atuin-common", version = "0.8.1" } -log = "0.4" +tracing = "0.1" chrono = { version = "0.4", features = ["serde"] } eyre = "0.6" uuid = { version = "0.8", features = ["v4"] } diff --git a/atuin-server/src/database.rs b/atuin-server/src/database.rs index efde86a3f84..5fd8d852c43 100644 --- a/atuin-server/src/database.rs +++ b/atuin-server/src/database.rs @@ -1,4 +1,5 @@ use async_trait::async_trait; +use tracing::debug; use std::collections::HashMap; use sqlx::{postgres::PgPoolOptions, Result}; diff --git a/atuin-server/src/handlers/history.rs b/atuin-server/src/handlers/history.rs index 4fa2a9620c2..38d8f26e870 100644 --- a/atuin-server/src/handlers/history.rs +++ b/atuin-server/src/handlers/history.rs @@ -1,6 +1,7 @@ use axum::extract::Query; use axum::{extract::Path, Extension, Json}; use http::StatusCode; +use tracing::{error, debug}; use std::collections::HashMap; use crate::database::{Database, Postgres}; diff --git a/atuin-server/src/handlers/user.rs b/atuin-server/src/handlers/user.rs index 42e4aa33591..d5f924e1dfd 100644 --- a/atuin-server/src/handlers/user.rs +++ b/atuin-server/src/handlers/user.rs @@ -6,6 +6,7 @@ use axum::extract::Path; use axum::{Extension, Json}; use http::StatusCode; use sodiumoxide::crypto::pwhash::argon2id13; +use tracing::{debug, error}; use uuid::Uuid; use crate::database::{Database, Postgres}; diff --git a/atuin-server/src/lib.rs b/atuin-server/src/lib.rs index 02b3fdaefa9..8811986e5d5 100644 --- a/atuin-server/src/lib.rs +++ b/atuin-server/src/lib.rs @@ -8,9 +8,6 @@ use eyre::{Context, Result}; use crate::settings::Settings; -#[macro_use] -extern crate log; - #[macro_use] extern crate serde_derive; diff --git a/src/command/server.rs b/src/command/server.rs index cd05caca4cb..4a04c91d1ef 100644 --- a/src/command/server.rs +++ b/src/command/server.rs @@ -1,3 +1,5 @@ +use tracing_subscriber::{EnvFilter, fmt, prelude::*}; + use clap::Parser; use eyre::{Context, Result}; @@ -21,7 +23,10 @@ pub enum Cmd { impl Cmd { pub async fn run(self) -> Result<()> { - pretty_env_logger::init(); + tracing_subscriber::registry() + .with(fmt::layer()) + .with(EnvFilter::from_default_env()) + .init(); let settings = Settings::new().wrap_err("could not load server settings")?; From 0938bbcfee2ca6216c5d13ca2c4912f61b55f7e4 Mon Sep 17 00:00:00 2001 From: Conrad Ludgate Date: Wed, 20 Apr 2022 20:58:55 +0100 Subject: [PATCH 2/3] fmt --- atuin-server/src/database.rs | 2 +- atuin-server/src/handlers/history.rs | 2 +- src/command/server.rs | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/atuin-server/src/database.rs b/atuin-server/src/database.rs index 5fd8d852c43..1ce08f08ba9 100644 --- a/atuin-server/src/database.rs +++ b/atuin-server/src/database.rs @@ -1,6 +1,6 @@ use async_trait::async_trait; -use tracing::debug; use std::collections::HashMap; +use tracing::debug; use sqlx::{postgres::PgPoolOptions, Result}; diff --git a/atuin-server/src/handlers/history.rs b/atuin-server/src/handlers/history.rs index 38d8f26e870..258f80a1ec6 100644 --- a/atuin-server/src/handlers/history.rs +++ b/atuin-server/src/handlers/history.rs @@ -1,8 +1,8 @@ use axum::extract::Query; use axum::{extract::Path, Extension, Json}; use http::StatusCode; -use tracing::{error, debug}; use std::collections::HashMap; +use tracing::{debug, error}; use crate::database::{Database, Postgres}; use crate::models::{NewHistory, User}; diff --git a/src/command/server.rs b/src/command/server.rs index 4a04c91d1ef..c5af9ae5f3e 100644 --- a/src/command/server.rs +++ b/src/command/server.rs @@ -1,4 +1,4 @@ -use tracing_subscriber::{EnvFilter, fmt, prelude::*}; +use tracing_subscriber::{fmt, prelude::*, EnvFilter}; use clap::Parser; use eyre::{Context, Result}; From a0a198f786164e64d7da8613dee32bdfa5142799 Mon Sep 17 00:00:00 2001 From: Conrad Ludgate Date: Wed, 20 Apr 2022 21:15:58 +0100 Subject: [PATCH 3/3] instrument handlers --- Cargo.lock | 3 +++ atuin-server/Cargo.toml | 2 ++ atuin-server/src/database.rs | 18 +++++++++++++++++- atuin-server/src/handlers/history.rs | 6 +++++- atuin-server/src/handlers/user.rs | 5 ++++- atuin-server/src/router.rs | 10 ++++++++-- 6 files changed, 39 insertions(+), 5 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 7889e48553a..7fed6667a90 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -167,6 +167,8 @@ dependencies = [ "sodiumoxide", "sqlx", "tokio", + "tower", + "tower-http", "tracing", "uuid", "whoami", @@ -2476,6 +2478,7 @@ dependencies = [ "tower", "tower-layer", "tower-service", + "tracing", ] [[package]] diff --git a/atuin-server/Cargo.toml b/atuin-server/Cargo.toml index 92f4bd03b59..33f5f7cd75a 100644 --- a/atuin-server/Cargo.toml +++ b/atuin-server/Cargo.toml @@ -31,3 +31,5 @@ axum = "0.5" http = "0.2" fs-err = "2.7" chronoutil = "0.2.3" +tower = "0.4" +tower-http = { version = "0.2", features = ["trace"] } diff --git a/atuin-server/src/database.rs b/atuin-server/src/database.rs index 1ce08f08ba9..2d3f8be1dcf 100644 --- a/atuin-server/src/database.rs +++ b/atuin-server/src/database.rs @@ -1,6 +1,6 @@ use async_trait::async_trait; use std::collections::HashMap; -use tracing::debug; +use tracing::{debug, instrument}; use sqlx::{postgres::PgPoolOptions, Result}; @@ -78,6 +78,7 @@ impl Postgres { #[async_trait] impl Database for Postgres { + #[instrument(skip_all)] async fn get_session(&self, token: &str) -> Result { sqlx::query_as::<_, Session>("select * from sessions where token = $1") .bind(token) @@ -85,6 +86,7 @@ impl Database for Postgres { .await } + #[instrument(skip_all)] async fn get_user(&self, username: &str) -> Result { sqlx::query_as::<_, User>("select * from users where username = $1") .bind(username) @@ -92,6 +94,7 @@ impl Database for Postgres { .await } + #[instrument(skip_all)] async fn get_session_user(&self, token: &str) -> Result { sqlx::query_as::<_, User>( "select * from users @@ -104,6 +107,7 @@ impl Database for Postgres { .await } + #[instrument(skip_all)] async fn count_history(&self, user: &User) -> Result { // The cache is new, and the user might not yet have a cache value. // They will have one as soon as they post up some new history, but handle that @@ -120,6 +124,7 @@ impl Database for Postgres { Ok(res.0) } + #[instrument(skip_all)] async fn count_history_cached(&self, user: &User) -> Result { let res: (i32,) = sqlx::query_as( "select total from total_history_count_user @@ -132,6 +137,7 @@ impl Database for Postgres { Ok(res.0 as i64) } + #[instrument(skip_all)] async fn count_history_range( &self, user: &User, @@ -154,6 +160,7 @@ impl Database for Postgres { } // Count the history for a given year + #[instrument(skip_all)] async fn count_history_year(&self, user: &User, year: i32) -> Result { let start = chrono::Utc.ymd(year, 1, 1).and_hms_nano(0, 0, 0, 0); let end = start + RelativeDuration::years(1); @@ -165,6 +172,7 @@ impl Database for Postgres { } // Count the history for a given month + #[instrument(skip_all)] async fn count_history_month(&self, user: &User, month: chrono::NaiveDate) -> Result { let start = chrono::Utc .ymd(month.year(), month.month(), 1) @@ -190,6 +198,7 @@ impl Database for Postgres { } // Count the history for a given day + #[instrument(skip_all)] async fn count_history_day(&self, user: &User, day: chrono::NaiveDate) -> Result { let start = chrono::Utc .ymd(day.year(), day.month(), day.day()) @@ -204,6 +213,7 @@ impl Database for Postgres { Ok(res) } + #[instrument(skip_all)] async fn list_history( &self, user: &User, @@ -231,6 +241,7 @@ impl Database for Postgres { Ok(res) } + #[instrument(skip_all)] async fn add_history(&self, history: &[NewHistory]) -> Result<()> { let mut tx = self.pool.begin().await?; @@ -260,6 +271,7 @@ impl Database for Postgres { Ok(()) } + #[instrument(skip_all)] async fn add_user(&self, user: &NewUser) -> Result { let email: &str = &user.email; let username: &str = &user.username; @@ -280,6 +292,7 @@ impl Database for Postgres { Ok(res.0) } + #[instrument(skip_all)] async fn add_session(&self, session: &NewSession) -> Result<()> { let token: &str = &session.token; @@ -296,6 +309,7 @@ impl Database for Postgres { Ok(()) } + #[instrument(skip_all)] async fn get_user_session(&self, u: &User) -> Result { sqlx::query_as::<_, Session>("select * from sessions where user_id = $1") .bind(u.id) @@ -303,6 +317,7 @@ impl Database for Postgres { .await } + #[instrument(skip_all)] async fn oldest_history(&self, user: &User) -> Result { let res = sqlx::query_as::<_, History>( "select * from history @@ -317,6 +332,7 @@ impl Database for Postgres { Ok(res) } + #[instrument(skip_all)] async fn calendar( &self, user: &User, diff --git a/atuin-server/src/handlers/history.rs b/atuin-server/src/handlers/history.rs index 258f80a1ec6..b7112526a51 100644 --- a/atuin-server/src/handlers/history.rs +++ b/atuin-server/src/handlers/history.rs @@ -2,7 +2,7 @@ use axum::extract::Query; use axum::{extract::Path, Extension, Json}; use http::StatusCode; use std::collections::HashMap; -use tracing::{debug, error}; +use tracing::{debug, error, instrument}; use crate::database::{Database, Postgres}; use crate::models::{NewHistory, User}; @@ -10,6 +10,7 @@ use atuin_common::api::*; use crate::calendar::{TimePeriod, TimePeriodInfo}; +#[instrument(skip_all, fields(user.id = user.id))] pub async fn count( user: User, db: Extension, @@ -28,6 +29,7 @@ pub async fn count( } } +#[instrument(skip_all, fields(user.id = user.id))] pub async fn list( req: Query, user: User, @@ -63,6 +65,7 @@ pub async fn list( Ok(Json(SyncHistoryResponse { history })) } +#[instrument(skip_all, fields(user.id = user.id))] pub async fn add( Json(req): Json>, user: User, @@ -91,6 +94,7 @@ pub async fn add( Ok(()) } +#[instrument(skip_all, fields(user.id = user.id))] pub async fn calendar( Path(focus): Path, Query(params): Query>, diff --git a/atuin-server/src/handlers/user.rs b/atuin-server/src/handlers/user.rs index d5f924e1dfd..a9a48fdcdf4 100644 --- a/atuin-server/src/handlers/user.rs +++ b/atuin-server/src/handlers/user.rs @@ -6,7 +6,7 @@ use axum::extract::Path; use axum::{Extension, Json}; use http::StatusCode; use sodiumoxide::crypto::pwhash::argon2id13; -use tracing::{debug, error}; +use tracing::{debug, error, instrument}; use uuid::Uuid; use crate::database::{Database, Postgres}; @@ -27,6 +27,7 @@ pub fn verify_str(secret: &str, verify: &str) -> bool { } } +#[instrument(skip_all, fields(user.username = username.as_str()))] pub async fn get( Path(username): Path, db: Extension, @@ -49,6 +50,7 @@ pub async fn get( })) } +#[instrument(skip_all)] pub async fn register( Json(register): Json, settings: Extension, @@ -96,6 +98,7 @@ pub async fn register( } } +#[instrument(skip_all, fields(user.username = login.username.as_str()))] pub async fn login( login: Json, db: Extension, diff --git a/atuin-server/src/router.rs b/atuin-server/src/router.rs index 146cc991610..9b525e05a8f 100644 --- a/atuin-server/src/router.rs +++ b/atuin-server/src/router.rs @@ -7,6 +7,8 @@ use axum::{ Extension, Router, }; use eyre::Result; +use tower::ServiceBuilder; +use tower_http::trace::TraceLayer; use super::{ database::{Database, Postgres}, @@ -65,6 +67,10 @@ pub fn router(postgres: Postgres, settings: Settings) -> Router { .route("/register", post(handlers::user::register)) .route("/login", post(handlers::user::login)) .fallback(teapot.into_service()) - .layer(Extension(postgres)) - .layer(Extension(settings)) + .layer( + ServiceBuilder::new() + .layer(TraceLayer::new_for_http()) + .layer(Extension(postgres)) + .layer(Extension(settings)), + ) }