🏡 index : ~doyle/chartered.git

author Jordan Doyle <jordan@doyle.la> 2021-09-12 23:44:57.0 +01:00:00
committer Jordan Doyle <jordan@doyle.la> 2021-09-13 0:12:01.0 +01:00:00
commit
061026e1155929b072b4f5b1aee748fa1cd565db [patch]
tree
b5bbdec16ed33f65a664228fb0feb2160856cf7f
parent
e0fa194583615e821dc82b72276352394f4a8443
download
061026e1155929b072b4f5b1aee748fa1cd565db.tar.gz

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(-)

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::<std::net::SocketAddr, _>())
        .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<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
            }
        }
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<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 {
        // 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::<std::net::SocketAddr>::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::<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()
}
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;