From c0a5bc81a02b1ed041a85256234da3c53ec6834d Mon Sep 17 00:00:00 2001 From: alyssa Date: Tue, 30 Sep 2025 03:30:43 +0000 Subject: [PATCH] feat(api): improve logging --- crates/api/src/main.rs | 5 +--- crates/api/src/middleware/auth.rs | 7 ++++- crates/api/src/middleware/logger.rs | 42 +++++++++++++++++++---------- 3 files changed, 35 insertions(+), 19 deletions(-) diff --git a/crates/api/src/main.rs b/crates/api/src/main.rs index f22450ce..5c2bcfd4 100644 --- a/crates/api/src/main.rs +++ b/crates/api/src/main.rs @@ -127,13 +127,10 @@ fn router(ctx: ApiContext) -> Router { .route("/v2/groups/{group_id}/oembed.json", get(rproxy)) .layer(middleware::ratelimit::ratelimiter(middleware::ratelimit::do_request_ratelimited)) // this sucks - .layer(axum::middleware::from_fn(middleware::ignore_invalid_routes::ignore_invalid_routes)) - .layer(axum::middleware::from_fn(middleware::logger::logger)) - .layer(axum::middleware::from_fn_with_state(ctx.clone(), middleware::params::params)) .layer(axum::middleware::from_fn_with_state(ctx.clone(), middleware::auth::auth)) - + .layer(axum::middleware::from_fn(middleware::logger::logger)) .layer(axum::middleware::from_fn(middleware::cors::cors)) .layer(tower_http::catch_panic::CatchPanicLayer::custom(util::handle_panic)) diff --git a/crates/api/src/middleware/auth.rs b/crates/api/src/middleware/auth.rs index 1d536e97..8487e932 100644 --- a/crates/api/src/middleware/auth.rs +++ b/crates/api/src/middleware/auth.rs @@ -76,5 +76,10 @@ pub async fn auth(State(ctx): State, mut req: Request, next: Next) - req.extensions_mut() .insert(AuthState::new(authed_system_id, authed_app_id, internal)); - next.run(req).await + let mut res = next.run(req).await; + + res.extensions_mut() + .insert(AuthState::new(authed_system_id, authed_app_id, internal)); + + res } diff --git a/crates/api/src/middleware/logger.rs b/crates/api/src/middleware/logger.rs index 512234bb..5e0ba782 100644 --- a/crates/api/src/middleware/logger.rs +++ b/crates/api/src/middleware/logger.rs @@ -12,9 +12,10 @@ const MIN_LOG_TIME: u128 = 2_000; pub async fn logger(request: Request, next: Next) -> Response { let method = request.method().clone(); + let headers = request.headers().clone(); - let remote_ip = header_or_unknown(request.headers().get("X-PluralKit-Client-IP")); - let user_agent = header_or_unknown(request.headers().get("User-Agent")); + let remote_ip = header_or_unknown(headers.get("X-PluralKit-Client-IP")); + let user_agent = header_or_unknown(headers.get("User-Agent")); let extensions = request.extensions().clone(); @@ -24,10 +25,6 @@ pub async fn logger(request: Request, next: Next) -> Response { .map(|v| v.as_str().to_string()) .unwrap_or("unknown".to_string()); - let auth = extensions - .get::() - .expect("should always have AuthState"); - let uri = request.uri().clone(); let request_span = span!( @@ -43,15 +40,24 @@ pub async fn logger(request: Request, next: Next) -> Response { let response = next.run(request).instrument(request_span).await; let elapsed = start.elapsed().as_millis(); - let system_id = auth - .system_id() - .map(|v| v.to_string()) - .unwrap_or("none".to_string()); + let rext = response.extensions().clone(); + let auth = rext.get::(); - let app_id = auth - .app_id() - .map(|v| v.to_string()) - .unwrap_or("none".to_string()); + let system_id = if let Some(auth) = auth { + auth.system_id() + .map(|v| v.to_string()) + .unwrap_or("none".to_string()) + } else { + "none".to_string() + }; + + let app_id = if let Some(auth) = auth { + auth.app_id() + .map(|v| v.to_string()) + .unwrap_or("none".to_string()) + } else { + "none".to_string() + }; counter!( "pluralkit_api_requests", @@ -73,6 +79,14 @@ pub async fn logger(request: Request, next: Next) -> Response { .record(elapsed as f64 / 1_000_f64); info!( + status = response.status().as_str(), + method = method.to_string(), + endpoint, + elapsed, + user_agent, + remote_ip, + system_id, + app_id, "{} handled request for {} {} in {}ms", response.status(), method,