api: a log line per HTTP request

Requests weren't logged at all, short of what a handler logs itself. Now a middleware,
outermost on the API (and on a relay-only node's), logs a line per request as web
servers do: method and path (with the query), status, the milliseconds until the answer
began (a stream goes on after), where it came from (the address, or `unix`), and the
user (`-` where none was authenticated). The user comes back on the response:
`basic_auth` puts it there, for a token as for a password or a trusted proxy's header.

At debug, under the target `http` (`RUST_LOG=info,http=debug`, or `PUT /admin/log`):
an open dashboard alone would fill the log at info. With the target off, the request
passes untouched.

1 files changed, 49 insertions, 0 deletions

diff --git a/src/api/request_log.rs b/src/api/request_log.rs
new file mode 100644
index 0000000..418fe14
--- /dev/null
+++ b/src/api/request_log.rs
@@ -0,0 +1,49 @@
+//! A line per HTTP request, as web servers log them: the method and path, the status,
+//! how long until the answer began (a stream, such as the dashboard's events, goes on
+//! after), where it came from, and the user. At debug, under the target `http`
+//! (`RUST_LOG=info,http=debug`, or `PUT /admin/log`): an open dashboard alone would
+//! fill the log at info.
+
+use axum::extract::{ConnectInfo, Request};
+use axum::middleware::Next;
+use axum::response::Response;
+use tokio::time::Instant;
+use tracing::{Level, debug, enabled};
+
+use super::auth::AuthenticatedUser;
+use super::listen::Peer;
+
+/// Outermost: what the layers inside answer too (a `401` included). The user comes back
+/// on the response (`auth::basic_auth`).
+pub(crate) async fn log_requests(request: Request, next: Next) -> Response {
+    if !enabled!(target: "http", Level::DEBUG) {
+        return next.run(request).await;
+    }
+    let method = request.method().clone();
+    let path = request
+        .uri()
+        .path_and_query()
+        .map_or_else(|| request.uri().path().to_owned(), ToString::to_string);
+    let from = match request.extensions().get::<ConnectInfo<Peer>>() {
+        Some(ConnectInfo(Peer::Tcp(address))) => address.to_string(),
+        Some(ConnectInfo(Peer::Unix)) => "unix".to_owned(),
+        None => "-".to_owned(),
+    };
+    let started = Instant::now();
+    let response = next.run(request).await;
+    let user = response
+        .extensions()
+        .get::<AuthenticatedUser>()
+        .map_or("-", |AuthenticatedUser(user)| user.as_str());
+    debug!(
+        target: "http",
+        method = %method,
+        path = %path,
+        status = response.status().as_u16(),
+        ms = started.elapsed().as_millis(),
+        from = %from,
+        user = %user,
+        "HTTP request"
+    );
+    response
+}