feat(telemetry): add JSON log format

config.yaml

@@ -339,6 +339,9 @@ credits:
 # Optional feature toggles
 enable_metrics: true # Enable Prometheus metrics endpoint
 enable_request_logging: true # Enable request/response logging to database
+# Log output format: compact (human-readable lines) or json (one JSON object
+# per event, for log aggregators). Override with DWCTL_LOG_FORMAT.
+log_format: compact
 
 # Opt-in heap profile listener (GET /debug/pprof/heap, gzip pprof). Profiles exist
 # only if the process also starts with jemalloc sampling on, e.g.

docs/src/reference/configuration.md

@@ -808,6 +808,42 @@ does not itself enable span export: correlation also depends on the connecting
 spans being sampled, exported, and retained. Stored IDs can therefore refer to
 unavailable spans, and older analytics records may have no gateway span ID.
 
+### Log Format
+
+```yaml
+log_format: compact
+```
+
+`compact` writes human-readable text for each event; a multi-line message or
+error spans several lines. `json` writes one JSON object per event, for log
+aggregators: `timestamp`, `level`, `message` and `target`, the event's own
+fields at the top level, the innermost span under `span` and every enclosing
+span, root first, under `spans`. A multi-line error stays on one line. In
+`json` mode panics are written to stderr in the same shape, with `target` set
+to `panic` and a message that starts like Rust's default panic output
+(`thread '…' panicked at …`). They include the spans the panic happened in
+when there are any; a panic outside every span, or inside the logging
+subscriber itself, has none. The
+error `dwctl` exits with, including a configuration that fails to load, is
+logged once as `dwctl exited with an error`.
+
+Every JSON line logged while handling a request carries `x_request_id` at the
+top level: the ID dwctl mints, returns in the `X-Request-ID` header and
+forwards to providers. Other IDs are added at the top level once they are
+known: `edge_request_id` when the request arrived with its own
+`X-Request-ID` (for example from an ingress), `trace_id` when the request
+has a trace context, and `provider_request_id` on lines logged after the
+provider's response returned its own `X-Request-ID`. Analytics logs written
+after the response carry `x_request_id` too. Find every line of a request, in dwctl and in any
+provider that logs `x_request_id` the same way, with one query:
+
+```logql
+{namespace=~"<namespaces>"} |= "<id>" | json | x_request_id="<id>"
+```
+
+Queries and alerts that match text in compact lines need updating when you
+switch, since the same event reads differently in each format.
+
 ## Sample Files
 
 Generate sample JSONL files for new users:

dwctl/Cargo.toml

@@ -54,7 +54,9 @@ anyhow = "1.0"
 arc-swap = "1.7"
 log = "0.4"
 tracing = "0.1"
-tracing-subscriber = { version = "0.3", features = ["env-filter"] }
+# `tracing-log` forwards `log`-crate events (from dependencies) into tracing.
+# It is a default feature, listed so it survives `default-features = false`.
+tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "tracing-log"] }
 # OpenTelemetry
 opentelemetry = "0.32.0"
 opentelemetry_sdk = { version = "0.32", features = ["rt-tokio"] }

dwctl/src/config.rs

@@ -176,6 +176,9 @@ pub struct Config {
     pub analytics: AnalyticsConfig,
     /// Enable OpenTelemetry OTLP export for distributed tracing
     pub enable_otel_export: bool,
+    /// Log output format: `compact` (human-readable lines) or `json` (one
+    /// JSON object per event, for log aggregators)
+    pub log_format: LogFormat,
     /// Credit system configuration
     pub credits: CreditsConfig,
     /// Sample file generation configuration for new users
@@ -2042,6 +2045,19 @@ impl BatchConfig {
     }
 }
 
+/// How log events are written to stdout.
+#[derive(Debug, Clone, Copy, Default, Deserialize, Serialize, PartialEq, Eq)]
+#[serde(rename_all = "snake_case")]
+pub enum LogFormat {
+    /// One human-readable line per event.
+    #[default]
+    Compact,
+    /// One JSON object per event, with the event's fields at the top level
+    /// and the spans it occurred in under `span` and `spans`. Panics are
+    /// written in the same shape.
+    Json,
+}
+
 /// Which fusillade claim loops should run inside this daemon process.
 #[derive(Debug, Clone, Copy, Default, Deserialize, Serialize, PartialEq, Eq)]
 #[serde(rename_all = "snake_case")]
@@ -3463,6 +3479,7 @@ impl Default for Config {
             enable_analytics: true,
             analytics: AnalyticsConfig::default(),
             enable_otel_export: false,
+            log_format: LogFormat::default(),
             credits: CreditsConfig::default(),
             sample_files: SampleFilesConfig::default(),
             limits: LimitsConfig::default(),

dwctl/src/db/handlers/api_keys.rs

@@ -2566,6 +2566,7 @@ mod tests {
             enable_analytics: true,
             analytics: Default::default(),
             enable_otel_export: false,
+            log_format: Default::default(),
             credits: Default::default(),
             batches: Default::default(),
             background_services: crate::config::BackgroundServicesConfig::default(),

dwctl/src/lib.rs

@@ -99,7 +99,7 @@
 //!     let config = Config::load(&args)?;
 //!
 //!     // Initialize telemetry (structured logging and optional OpenTelemetry)
-//!     let tracer_provider = dwctl::telemetry::init_telemetry(config.enable_otel_export)?;
+//!     let tracer_provider = dwctl::telemetry::init_telemetry(config.enable_otel_export, config.log_format)?;
 //!
 //!     // Create and start the application
 //!     let app = Application::new(config, tracer_provider).await?;
@@ -2782,8 +2782,10 @@ pub async fn build_router(
     // Add tracing layer with OTel-compatible span names and HTTP semantic conventions.
     // Tracing span fields appear on every fmt log line in the request, so only the
     // correlation keys are fields: trace_id, otel.name, x_request_id,
-    // edge_request_id and provider_request_id (the request IDs are what
-    // `|= "x_request_id=<id>"` log queries match on), plus otel.kind, which the
+    // edge_request_id and provider_request_id (the request IDs are what log
+    // queries match on: `|= "x_request_id=<id>"` on compact lines, and
+    // `| json | x_request_id="<id>"` on JSON lines, which repeat them at the
+    // top level; see `telemetry::CORRELATION_FIELDS`), plus otel.kind, which the
     // tracing-opentelemetry layer only reads from a field (as a raw attribute it
     // is ignored and the span exports as `internal`). All other attributes are
     // set via OpenTelemetrySpanExt::set_attribute() so they're exported to the

dwctl/src/main.rs

@@ -1,3 +1,6 @@
+use std::process::ExitCode;
+
+use anyhow::Context;
 use clap::{Parser, Subcommand};
 use dwctl::config::Args;
 use dwctl::{Application, Config, migrations, telemetry};
@@ -79,14 +82,38 @@ async fn shutdown_signal() {
     }
 }
 
-fn main() -> anyhow::Result<()> {
-    tokio::runtime::Builder::new_multi_thread()
+fn main() -> ExitCode {
+    let result = tokio::runtime::Builder::new_multi_thread()
         .enable_all()
         // 8MB stack per worker thread — the default 2MB overflows with deep
         // tracing-opentelemetry span nesting during batch request processing
         .thread_stack_size(8 * 1024 * 1024)
-        .build()?
-        .block_on(async_main())
+        .build()
+        .map_err(anyhow::Error::from)
+        .and_then(|runtime| runtime.block_on(async_main()));
+    match result {
+        Ok(()) => ExitCode::SUCCESS,
+        Err(error) => {
+            report_error(&error);
+            ExitCode::FAILURE
+        }
+    }
+}
+
+/// Reports the error `dwctl` exits with, once: through tracing when logging
+/// is installed, so it comes out in the configured format, and as plain text
+/// on stderr when it isn't (logging itself failed to start). Returning the
+/// error from `main` instead would print it a second time, as plain text,
+/// beside the log line.
+fn report_error(error: &anyhow::Error) {
+    if tracing::dispatcher::has_been_set() {
+        // `{:#}` prints the context chain (target, migration version) ahead
+        // of the underlying error, which is what an operator reading a failed
+        // pod or Job needs first.
+        tracing::error!(error = format!("{error:#}"), "dwctl exited with an error");
+    } else {
+        eprintln!("Error: {error:?}");
+    }
 }
 
 /// `dwctl` serves by default; `dwctl migrate` applies schema migrations and
@@ -121,38 +148,41 @@ async fn async_main() -> anyhow::Result<()> {
     let cli = Cli::parse();
     let args = cli.args;
 
-    // Load configuration
-    let config = Config::load(&args)?;
+    // Load configuration. A config that fails to load still says how to log
+    // the failure, when `log_format` itself can be read from it.
+    let config = match Config::load(&args) {
+        Ok(config) => config,
+        Err(error) => {
+            let log_format = Config::figment(&args).extract_inner("log_format").unwrap_or_default();
+            let _ = telemetry::init_telemetry(false, log_format);
+            return Err(anyhow::Error::from(error).context("Failed to load configuration"));
+        }
+    };
+
+    // Initialize telemetry (tracing + optional OpenTelemetry) before anything
+    // logs: events emitted earlier have no subscriber and are discarded.
+    let tracer_provider = telemetry::init_telemetry(config.enable_otel_export, config.log_format)?;
 
     // Validate config consistency
     config.batches.validate();
 
     // If --validate flag is set, exit successfully after config validation
     if args.validate {
+        if let Some(provider) = tracer_provider {
+            let _ = provider.shutdown();
+        }
         println!("Configuration is valid.");
         return Ok(());
     }
 
-    // Initialize telemetry (tracing + optional OpenTelemetry)
-    let tracer_provider = telemetry::init_telemetry(config.enable_otel_export)?;
-
     tracing::debug!("{:?}", args);
 
     if let Some(Command::Migrate { check }) = cli.command {
         let result = migrations::run_command(&config, check).await;
         if let Some(provider) = tracer_provider {
             let _ = provider.shutdown();
         }
-        return match result {
-            Ok(_) => Ok(()),
-            Err(error) => {
-                // `{:#}` prints the context chain (target, migration version)
-                // ahead of the driver error, which is what an operator reading
-                // a failed Job needs first.
-                tracing::error!(error = format!("{error:#}"), "dwctl migrate failed");
-                Err(error)
-            }
-        };
+        return result.map(|_| ()).context("dwctl migrate failed");
     }
 
     // Run the application with graceful shutdown on SIGTERM/Ctrl+C

dwctl/src/request_logging/analytics_handler.rs

@@ -212,8 +212,15 @@ impl RequestHandler for AnalyticsHandler {
         let span = info_span!(
             "dwctl.analytics_handler",
             correlation_id = correlation_id,
-            status = %response_data.status
+            status = %response_data.status,
+            x_request_id = tracing::field::Empty,
         );
+        // This runs after the response, outside the request span, so it
+        // carries the request's ID itself for the analytics logs to be found
+        // by it. `assign_request_id` set the header before outlet captured it.
+        if let Some(x_request_id) = extract_header_as_string(&request_data, "x-request-id") {
+            span.record("x_request_id", tracing::field::display(x_request_id));
+        }
 
         async {
             // Whether this is a token-bearing generative endpoint. Gates the
@@ -265,8 +272,8 @@ impl RequestHandler for AnalyticsHandler {
                     correlation_id = correlation_id,
                     uri = %request_data.uri,
                     response_type = %metrics.response_type,
-                    request_model = ?metrics.request_model,
-                    response_model = ?metrics.response_model,
+                    request_model = metrics.request_model.as_deref(),
+                    response_model = metrics.response_model.as_deref(),
                     client_disconnected = client_disconnected(&response_data),
                     "Successful generative response recorded zero tokens"
                 );