http server request logging with errors
Diff
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(-)
@@ -254,11 +254,14 @@
"chartered-db",
"chartered-fs",
"chartered-types",
"chrono",
"env_logger",
"futures",
"hex",
"log",
"nom",
"once_cell",
"regex",
"serde",
"serde_json",
"sha2",
@@ -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"
@@ -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();
@@ -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::<std::net::SocketAddr, _>())
.await
.unwrap();
}
@@ -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<axum::body::Bytes>;
type BodyError = <Self::Body as axum::body::HttpBody>::Error;
fn into_response(self) -> axum::http::Response<Self::Body> {
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<dyn crate::middleware::logging::GenericError>>(Box::new(self));
res
}
}
@@ -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<S>(pub S);
impl<S, ReqBody, ResBody> Service<Request<ReqBody>> for LoggingMiddleware<S>
where
S: Service<Request<ReqBody>, Response = Response<ResBody>, 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<Self::Response, Self::Error>>;
fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
self.0.poll_ready(cx)
}
fn call(&mut self, mut req: Request<ReqBody>) -> Self::Future {
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::<std::net::SocketAddr>::from_request(&mut req)
.await
.map_or_else(|_| "0.0.0.0:0".parse().unwrap(), |v| v.0);
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::<Box<dyn GenericError>>() {
Some(e) => Err(e),
None => Ok(()),
}
);
Ok(response)
})
}
}
fn replace_sensitive_path(uri: &str) -> String {
static SENSITIVE_REGEX: Lazy<Regex> = Lazy::new(|| Regex::new(r"^/a/(.*?)/").unwrap());
SENSITIVE_REGEX.replace(uri, "/a/[snip]/").into_owned()
}
@@ -1,1 +1,2 @@
pub mod auth;
pub mod logging;