feat: add structured per-request logging with client IP #2

Summary

Log every request with method, path, client_ip, status, and latency_ms via tower-http TraceLayer
Client IP extracted from x-forwarded-for / x-real-ip / socket addr — enables tracing requests across LB, gatekeeper, and PDS
Set GATEKEEPER_LOG_FORMAT=json for JSON structured logs; default stays human-readable

Example output

Default: INFO request{method=POST path=/xrpc/com.atproto.server.createSession client_ip=148.251.49.115}: response status=200 latency_ms=42

JSON (GATEKEEPER_LOG_FORMAT=json): {"timestamp":"...","level":"INFO","span":{"method":"POST","path":"/xrpc/com.atproto.server.createSession","client_ip":"148.251.49.115"},"fields":{"status":200,"latency_ms":42}}

Test plan

cargo test — all 26 tests pass
Manual: start server, hit endpoints, verify logs show IP/method/path/status/latency
Manual: set GATEKEEPER_LOG_FORMAT=json, verify JSON output

+58 -6

3 changed files

Diff round #0

expand all

Cargo.lock

Cargo.toml

src

main.rs

+14

Cargo.lock

··· 4202 4202 "tower", 4203 4203 "tower-layer", 4204 4204 "tower-service", 4205 + "tracing", 4205 4206 ] 4206 4207 4207 4208 [[package]] ··· 4277 4278 "tracing-core", 4278 4279 ] 4279 4280 4281 + [[package]] 4282 + name = "tracing-serde" 4283 + version = "0.2.0" 4284 + source = "registry+https://github.com/rust-lang/crates.io-index" 4285 + checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1" 4286 + dependencies = [ 4287 + "serde", 4288 + "tracing-core", 4289 + ] 4290 + 4280 4291 [[package]] 4281 4292 name = "tracing-subscriber" 4282 4293 version = "0.3.22" ··· 4287 4298 "nu-ansi-term", 4288 4299 "once_cell", 4289 4300 "regex-automata", 4301 + "serde", 4302 + "serde_json", 4290 4303 "sharded-slab", 4291 4304 "smallvec", 4292 4305 "thread_local", 4293 4306 "tracing", 4294 4307 "tracing-core", 4295 4308 "tracing-log", 4309 + "tracing-serde", 4296 4310 ] 4297 4311 4298 4312 [[package]]

+2 -2

Cargo.toml

··· 12 12 serde = { version = "1.0", features = ["derive"] } 13 13 serde_json = "1.0" 14 14 tracing = "0.1" 15 - tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt"] } 15 + tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt", "json"] } 16 16 hyper-util = { version = "0.1.19", features = ["client", "client-legacy"] } 17 - tower-http = { version = "0.6", features = ["cors", "compression-zstd"] } 17 + tower-http = { version = "0.6", features = ["cors", "compression-zstd", "trace"] } 18 18 tower_governor = { version = "0.8.0", features = ["axum", "tracing"] } 19 19 hex = "0.4" 20 20 jwt-compact = { version = "0.8.0", features = ["es256k"] }

+42 -4

src/main.rs

··· 33 33 use tower_http::{ 34 34 compression::CompressionLayer, 35 35 cors::{Any, CorsLayer}, 36 + trace::TraceLayer, 36 37 }; 37 38 use tracing::log; 38 39 use tracing_subscriber::{EnvFilter, fmt, prelude::*}; ··· 386 387 } 387 388 388 389 let app = app 390 + .layer(TraceLayer::new_for_http() 391 + .make_span_with(|req: &axum::http::Request<Body>| { 392 + let client_ip = req.headers() 393 + .get("x-forwarded-for") 394 + .and_then(|v| v.to_str().ok()) 395 + .and_then(|v| v.split(',').next()) 396 + .map(|s| s.trim().to_string()) 397 + .or_else(|| req.headers() 398 + .get("x-real-ip") 399 + .and_then(|v| v.to_str().ok()) 400 + .map(|s| s.trim().to_string())) 401 + .or_else(|| req.extensions() 402 + .get::<std::net::SocketAddr>() 403 + .map(|a| a.ip().to_string())) 404 + .unwrap_or_else(|| "-".to_string()); 405 + 406 + tracing::info_span!("request", 407 + method = %req.method(), 408 + path = %req.uri().path(), 409 + client_ip = %client_ip, 410 + ) 411 + }) 412 + .on_response(|resp: &axum::http::Response<Body>, latency: Duration, _span: &tracing::Span| { 413 + tracing::info!(status = resp.status().as_u16(), latency_ms = latency.as_millis() as u64, "response"); 414 + }) 415 + ) 389 416 .layer(CompressionLayer::new()) 390 417 .layer(cors) 391 418 .with_state(state); ··· 416 443 417 444 fn setup_tracing() { 418 445 let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info")); 419 - tracing_subscriber::registry() 420 - .with(env_filter) 421 - .with(fmt::layer()) 422 - .init(); 446 + let json_logging = env::var("GATEKEEPER_LOG_FORMAT") 447 + .map(|v| v.eq_ignore_ascii_case("json")) 448 + .unwrap_or(false); 449 + 450 + if json_logging { 451 + tracing_subscriber::registry() 452 + .with(env_filter) 453 + .with(fmt::layer().json()) 454 + .init(); 455 + } else { 456 + tracing_subscriber::registry() 457 + .with(env_filter) 458 + .with(fmt::layer()) 459 + .init(); 460 + } 423 461 } 424 462 425 463 async fn shutdown_signal() {

History

1 round 0 comments

eriko.eurosky.social submitted #0 4w

1 commit

expand

f2701d71

feat: add structured per-request logging with client IP

expand 0 comments

closed without merging