From 061026e1155929b072b4f5b1aee748fa1cd565db Mon Sep 17 00:00:00 2001 From: Jordan Doyle Date: Sun, 12 Sep 2021 23:44:57 +0100 Subject: [PATCH] http server request logging with errors --- Cargo.lock | 3 +++ chartered-web/Cargo.toml | 3 +++ chartered-fs/src/lib.rs | 1 + chartered-web/src/main.rs | 9 +++------ chartered-web/src/endpoints/mod.rs | 8 +++++--- chartered-web/src/middleware/logging.rs | 89 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ chartered-web/src/middleware/mod.rs | 1 + 7 files changed, 105 insertions(+), 9 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 03cf7b7..e05ae7f 100644 --- a/Cargo.lock +++ a/Cargo.lock @@ -254,11 +254,14 @@ "chartered-db", "chartered-fs", "chartered-types", + "chrono", "env_logger", "futures", "hex", "log", "nom", + "once_cell", + "regex", "serde", "serde_json", "sha2", diff --git a/chartered-web/Cargo.toml b/chartered-web/Cargo.toml index 7fe1c91..80c8d6f 100644 --- a/chartered-web/Cargo.toml +++ a/chartered-web/Cargo.toml @@ -12,11 +12,14 @@ axum = "0.2" bytes = "1" +chrono = "0.4" env_logger = "0.9" futures = "0.3" hex = "0.4" log = "0.4" nom = "7" +once_cell = "1.8" +regex = "1.5" serde = { version = "1", features = ["derive"] } serde_json = "1" sha2 = "0.9" diff --git a/chartered-fs/src/lib.rs b/chartered-fs/src/lib.rs index ec43145..a6e395d 100644 --- a/chartered-fs/src/lib.rs +++ a/chartered-fs/src/lib.rs @@ -108,6 +108,7 @@ use super::FileSystem; #[tokio::test] + #[allow(clippy::pedantic)] async fn local() { let fs = super::Local; let file_ref = fs.write(b"abcdef").await.unwrap(); diff --git a/chartered-web/src/main.rs b/chartered-web/src/main.rs index caad92c..0dad29b 100644 --- a/chartered-web/src/main.rs +++ a/chartered-web/src/main.rs @@ -8,7 +8,7 @@ handler::{delete, get, put}, AddExtensionLayer, Router, }; -use tower::{filter::AsyncFilterLayer, ServiceBuilder}; +use tower::ServiceBuilder; #[allow(clippy::unused_async)] async fn hello_world() -> &'static str { @@ -59,10 +59,7 @@ .layer(AddExtensionLayer::new(pool)); let middleware_stack = ServiceBuilder::new() - .layer(AsyncFilterLayer::new(|req| async { - eprintln!("{:#?}", req); - Ok::<_, std::convert::Infallible>(req) - })) + .layer_fn(middleware::logging::LoggingMiddleware) .into_inner(); let app = Router::new() @@ -71,7 +68,7 @@ .layer(middleware_stack); axum::Server::bind(&"0.0.0.0:8888".parse().unwrap()) - .serve(app.into_make_service()) + .serve(app.into_make_service_with_connect_info::()) .await .unwrap(); } diff --git a/chartered-web/src/endpoints/mod.rs b/chartered-web/src/endpoints/mod.rs index e6ed334..310a02f 100644 --- a/chartered-web/src/endpoints/mod.rs +++ a/chartered-web/src/endpoints/mod.rs @@ -5,13 +5,13 @@ macro_rules! define_error_response { ($error:ty) => { - impl axum::response::IntoResponse for Error { + impl crate::middleware::logging::GenericError for $error {} + + impl axum::response::IntoResponse for $error { type Body = axum::body::Full; type BodyError = ::Error; fn into_response(self) -> axum::http::Response { - eprintln!("error: {:?}", self); - let body = serde_json::to_vec(&crate::endpoints::ErrorResponse { error: self.to_string(), }) @@ -23,6 +23,8 @@ axum::http::header::CONTENT_TYPE, axum::http::header::HeaderValue::from_static("application/json"), ); + res.extensions_mut() + .insert::>(Box::new(self)); res } } diff --git a/chartered-web/src/middleware/logging.rs b/chartered-web/src/middleware/logging.rs new file mode 100644 index 0000000..7ccd855 100644 --- /dev/null +++ a/chartered-web/src/middleware/logging.rs @@ -1,0 +1,89 @@ +use axum::{ + extract::{self, FromRequest, RequestParts}, + http::{Request, Response}, +}; +use futures::future::BoxFuture; +use log::log; +use once_cell::sync::Lazy; +use regex::Regex; +use std::{ + fmt::Debug, + task::{Context, Poll}, +}; +use tower::Service; + +pub trait GenericError: std::error::Error + Debug + Send + Sync {} + +#[derive(Clone)] +pub struct LoggingMiddleware(pub S); + +impl Service> for LoggingMiddleware +where + S: Service, Response = Response, Error = std::convert::Infallible> + + Clone + + Send + + 'static, + S::Future: Send + 'static, + S::Response: Default + Debug, + ReqBody: Send + Debug + 'static, + ResBody: Default + Send + 'static, +{ + type Response = S::Response; + type Error = S::Error; + type Future = BoxFuture<'static, Result>; + + fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll> { + self.0.poll_ready(cx) + } + + fn call(&mut self, mut req: Request) -> Self::Future { + // best practice is to clone the inner service like this + // see https://github.com/tower-rs/tower/issues/547 for details + let clone = self.0.clone(); + let mut inner = std::mem::replace(&mut self.0, clone); + + Box::pin(async move { + let start = std::time::Instant::now(); + let user_agent = req.headers_mut().remove(axum::http::header::USER_AGENT); + let method = req.method().clone(); + let uri = replace_sensitive_path(req.uri().path()); + + let mut req = RequestParts::new(req); + let socket_addr = extract::ConnectInfo::::from_request(&mut req) + .await + .map_or_else(|_| "0.0.0.0:0".parse().unwrap(), |v| v.0); + + // this is infallible because of the type of S::Error + let response = inner.call(req.try_into_request().unwrap()).await?; + + log!( + if response.status().is_server_error() { + log::Level::Error + } else { + log::Level::Info + }, + "{ip} - \"{method} {uri}\" {status} {duration:?} \"{user_agent}\" \"{error:?}\"", + ip = socket_addr, + method = method, + uri = uri, + status = response.status().as_u16(), + duration = start.elapsed(), + user_agent = user_agent + .as_ref() + .and_then(|v| v.to_str().ok()) + .unwrap_or("unknown"), + error = match response.extensions().get::>() { + Some(e) => Err(e), + None => Ok(()), + } + ); + + Ok(response) + }) + } +} + +fn replace_sensitive_path(uri: &str) -> String { + static SENSITIVE_REGEX: Lazy = Lazy::new(|| Regex::new(r"^/a/(.*?)/").unwrap()); + SENSITIVE_REGEX.replace(uri, "/a/[snip]/").into_owned() +} diff --git a/chartered-web/src/middleware/mod.rs b/chartered-web/src/middleware/mod.rs index 0e4a05d..7eaa040 100644 --- a/chartered-web/src/middleware/mod.rs +++ a/chartered-web/src/middleware/mod.rs @@ -1,1 +1,2 @@ pub mod auth; +pub mod logging; -- rgit 0.1.3