From d30ac9c7aede4cbc6463ec1ee80b650b7bf9e9c7 Mon Sep 17 00:00:00 2001
From: tv <tv@krebsco.de>
Date: Mon, 9 Nov 2026 04:09:09 +0000
Subject: 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.
---
 src/api/request_log.rs | 49 +++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 49 insertions(+)
 create mode 100644 src/api/request_log.rs

(limited to 'src/api/request_log.rs')

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
+}
-- 
cgit v1.3.1