pacenotes_server/
access_log.rs

1//! One INFO line per response on target `access`, since production runs at
2//! INFO, where `TraceLayer` says nothing.
3
4/// Middleware logging method, target, status, bytes, time to the response head
5/// (a download's body is still streaming), the key's hash prefix and the agent.
6pub async fn log_response(
7    request: axum::extract::Request,
8    next: axum::middleware::Next,
9) -> axum::response::Response {
10    let started = std::time::Instant::now();
11    let method = request.method().clone();
12    let target = request
13        .uri()
14        .path_and_query()
15        .map(|path_and_query| path_and_query.as_str().to_string())
16        .unwrap_or_default();
17    let key = key_label(request.headers());
18    let agent = agent_label(request.headers());
19
20    let response = next.run(request).await;
21    tracing::info!(
22        target: "access",
23        method = %method,
24        target_uri = %target,
25        status = response.status().as_u16(),
26        bytes = %bytes_label(&response),
27        ms = started.elapsed().as_millis() as u64,
28        key = %key,
29        agent = %agent,
30        "request"
31    );
32    response
33}
34
35/// `-` without a key, `malformed` for one that could not be minted, otherwise
36/// the first 12 hex chars of its hash, as `token list` prints them; never the key.
37fn key_label(headers: &axum::http::HeaderMap) -> String {
38    match crate::auth::bearer_from_headers(headers) {
39        None => "-".to_string(),
40        Some(raw) if !crate::auth::well_formed(&raw) => "malformed".to_string(),
41        Some(raw) => crate::auth::hash_token(&raw)[..12].to_string(),
42    }
43}
44
45/// Bounded, and `to_str` admits only visible ASCII, so the agent cannot forge log lines.
46fn agent_label(headers: &axum::http::HeaderMap) -> String {
47    let agent = headers
48        .get(axum::http::header::USER_AGENT)
49        .and_then(|value| value.to_str().ok())
50        .unwrap_or("-");
51    agent.chars().take(200).collect()
52}
53
54/// `Content-Length` when the handler set it, otherwise the body's exact size,
55/// which hyper only turns into a header later.
56fn bytes_label(response: &axum::response::Response) -> String {
57    response
58        .headers()
59        .get(axum::http::header::CONTENT_LENGTH)
60        .and_then(|value| value.to_str().ok())
61        .map(str::to_string)
62        .or_else(|| {
63            <axum::body::Body as axum::body::HttpBody>::size_hint(response.body())
64                .exact()
65                .map(|size| size.to_string())
66        })
67        .unwrap_or_else(|| "-".to_string())
68}
69
70#[cfg(test)]
71mod tests {
72    fn authorization(value: &str) -> axum::http::HeaderMap {
73        let mut headers = axum::http::HeaderMap::new();
74        headers.insert(
75            axum::http::header::AUTHORIZATION,
76            axum::http::HeaderValue::from_str(value).unwrap(),
77        );
78        headers
79    }
80
81    #[test]
82    fn the_access_log_never_sees_a_raw_key() {
83        let key = crate::auth::mint_token();
84        let label = super::key_label(&authorization(&format!("Bearer {key}")));
85        assert_eq!(label, crate::auth::hash_token(&key)[..12]);
86        assert_eq!(super::key_label(&axum::http::HeaderMap::new()), "-");
87        assert_eq!(
88            super::key_label(&authorization("Bearer garbage")),
89            "malformed"
90        );
91    }
92}
pacenotes_server/access_log.rs

pacenotes_server/
access_log.rs
