feat(router): logger improvements, access logs

.changeset/logger_improvements_access_logs.md

@@ -0,0 +1,21 @@
+---
+hive-router-internal: patch
+hive-router-config: patch
+hive-router-plan-executor: patch
+hive-router: patch
+---
+
+# Logger improvements and access logs
+
+Reworked the router's logging for lower overhead and clearer output.
+
+- **Access logs:** at the default `info` level the router now emits a single per-request summary (`router::request` target) with operation, subgraph, error, status, payload size, and duration fields.
+- **Correlation:** every log line carries `request_id` (from the `log.correlation.id_header`, default `x-request-id`, or generated when absent) and `trace_id` (from the W3C `traceparent` context when `log.correlation.trace_propagation` is enabled).
+- **Explicit targets:** all logs use `router::*` targets, so `log.filter` (or `LOG_FILTER`) can raise or mute individual subsystems. To disable access logs entirely, set `LOG_FILTER=router::request=off`.
+- **Internal crates:** logs from dependencies like `ntex` and `hyper` are now suppressed unless `log.log_internals` (or `LOG_INTERNALS`) is enabled.
+- **Structured output:** flat JSON/text with no nested fields, formatted directly into buffers.
+
+**Breaking changes:**
+
+- The `trace` log level is no longer available in release builds.
+- The `pretty-tree` and `pretty-compact` log formats were removed; only `text` and `json` remain.

Cargo.toml

@@ -35,7 +35,7 @@ codegen-units = 1
 serde = { version = "1.0.219", features = ["derive"] }
 serde_json = "1.0.150"
 sonic-rs = "0.5.3"
-insta = { version = "1.42.1", features= ["filters"] }
+insta = { version = "1.42.1", features= ["filters", "json", "redactions"] }
 criterion = { version = "0.8", features = ["html_reports", "async_tokio"] }
 lazy_static = "1.5.0"
 dashmap = { version = "6.2.1" }
@@ -91,6 +91,7 @@ axum = "0.8.9"
 recloser = "1.3.1"
 notify = "8.2.0"
 ipnet = "2.12.0"
+ulid = "2.0.1"
 
 # Telemetry
 opentelemetry = "0.31.0"
@@ -105,14 +106,15 @@ opentelemetry-stdout = "0.31.0"
 opentelemetry-appender-tracing = "0.31.1"
 opentelemetry-jaeger-propagator = "0.31.0"
 opentelemetry-zipkin = { version = "0.31.0", default-features = false, features=["reqwest-rustls", "reqwest-client"] }
-tracing = "0.1.44"
+tracing = { version = "0.1.44", features = ["release_max_level_debug", "max_level_trace"] }
 tracing-opentelemetry = "0.32.0"
 tracing-subscriber = { version = "0.3.22", features = [
   "env-filter",
   "time",
   "json",
 ] }
 tracing-tree = "0.4.0"
+tracing-appender = "0.2.5"
 
 # Storage
 object_store = { version = "0.13.2", features = ["aws"] }

apollo-router-workspace/bin/router/src/persisted_documents.rs

@@ -20,7 +20,7 @@ use std::ops::ControlFlow;
 use std::sync::Arc;
 use std::time::Duration;
 use tower::{BoxError, ServiceBuilder, ServiceExt};
-use tracing::{debug, info, warn};
+use tracing::{debug, warn};
 
 use crate::consts::PLUGIN_VERSION;
 
@@ -233,7 +233,7 @@ impl Plugin for PersistedDocumentsPlugin {
                                 }
                                 match mgr.resolve_document(document_id).await {
                                     Ok(document) => {
-                                        info!("Document found in persisted documents: {}", document);
+                                        debug!("Document found in persisted documents: {}", document);
 
                                         if req
                                             .context

bin/router/Cargo.toml

@@ -37,7 +37,7 @@ reqwest = { workspace = true }
 sonic-rs = { workspace = true }
 tracing = { workspace = true }
 tracing-subscriber = { workspace = true }
-tracing-tree = { workspace = true }
+tracing-appender = { workspace = true }
 hyper = { workspace = true, features = ["server", "http1"] }
 http = { workspace = true }
 http-body-util = { workspace = true }

bin/router/src/jwt/jwks_manager.rs

@@ -1,5 +1,8 @@
 use hive_router_config::jwt_auth::{JwksProviderSourceConfig, JwtAuthConfig};
-use hive_router_internal::background_tasks::{BackgroundTask, BackgroundTasksManager};
+use hive_router_internal::{
+    background_tasks::{BackgroundTask, BackgroundTasksManager},
+    telemetry::logging::targets,
+};
 use sonic_rs::from_str;
 use std::sync::{Arc, RwLock};
 use tokio::fs::read_to_string;
@@ -29,7 +32,7 @@ impl JwksManager {
             .filter_map(|v| match v.get_jwk_set() {
                 Ok(set) => Some(set),
                 Err(err) => {
-                    error!("Failed to use JWK set: {}, ignoring", err);
+                    error!(target: targets::JWT, error = ?err, "failed to use jwt set, ignoring this set");
 
                     None
                 }
@@ -79,9 +82,10 @@ impl BackgroundTask for JwksSourceTask {
             ..
         } = &self.0.config
         {
-            debug!(
-                "Starting remote jwks polling for source: {:?}",
-                self.0.config
+            info!(
+                target: targets::JWT,
+                source = ?self.0.config,
+                "starting remote jwks polling for source",
             );
             let mut tokio_interval = tokio::time::interval(*interval);
 
@@ -90,10 +94,10 @@ impl BackgroundTask for JwksSourceTask {
                     _ = tokio_interval.tick() => { match self.0.load_and_store_jwks().await {
                         Ok(_) => {}
                         Err(err) => {
-                            error!("Failed to load remote jwks: {}", err);
+                            error!(target: targets::JWT, error = ?err, source = ?self.0.config, "failed to load remote jwks");
                         }
                     } }
-                    _ = token.cancelled() => { info!("Jwks source shutting down."); return; }
+                    _ = token.cancelled() => { info!(target: targets::JWT, "jwks source shutting down."); return; }
                 }
             }
         }
@@ -117,7 +121,7 @@ impl JwksSource {
         let jwks_str = match &self.config {
             JwksProviderSourceConfig::Remote { url, .. } => {
                 let client = reqwest::Client::new();
-                debug!("loading jwks from a remote source: {}", url);
+                debug!(target: targets::JWT, url = ?url, "loading jwks from a remote source");
 
                 let response_text = client
                     .get(url)
@@ -131,7 +135,7 @@ impl JwksSource {
                 response_text
             }
             JwksProviderSourceConfig::File { file, .. } => {
-                debug!("loading jwks from a file source: {}", file.absolute);
+                debug!(target: targets::JWT, path = ?file.absolute, "loading jwks from a file source");
 
                 let file_contents = read_to_string(&file.absolute)
                     .await