feat(telemetry): add JSON log format

Merged
TO
2d ago
+655-57

Adds log_format: compact | json (DWCTL_LOG_FORMAT). compact stays the default. json writes one object per event: timestamp, level, message, target, the event's fields at the top level, and the spans under span and spans (root first). Loki derives detected_level from level.

The setting covers every process that runs the dwctl binary (server, batch daemon, dwctl migrate), including onwards and fusillade, since they log through dwctl's subscriber.

Request IDs as top-level keys

In JSON, span fields sit inside the spans array, and Loki's json parser doesn't look into arrays. So every event inside a span that recorded x_request_id, edge_request_id, provider_request_id or trace_id also carries them at the top level. The innermost value wins, and an event's own field takes precedence. Panic lines carry them as well. The analytics handler runs after the response, outside the request span, so it now records the request's x_request_id on its own span. One query then finds a request across dwctl and any service that logs x_request_id the same way:

{namespace=~"<namespaces>"} |= "<id>" | json | x_request_id="<id>"

Not losing error logs in the switch

  • Panics: in JSON mode they are written to stderr as one JSON ERROR line with target: "panic", including the span/spans the panic happened in. The message starts like the default (thread '…' panicked at …). The hook writes the line itself, because a tracing event could be filtered out by RUST_LOG or never reach a subscriber if the panic happens inside one.
  • Exit errors: main reports the error dwctl exits with once, as dwctl exited with an error, in the configured format. That includes a config that fails to load (when log_format can still be read from it), an OTLP setup failure (logging is installed before the exporter is built) and a failed dwctl migrate. It's printed as plain text only if logging itself failed to start. Returning the error from main used to print it a second time as plain Error: … lines.
  • OTLP startup prints: the [OTLP] … eprintln! lines are now fields on the "Telemetry initialized" event.
  • An error that was already being dropped: batches.validate() emitted its error before telemetry started, so it was never written. Telemetry now starts first.
  • log-crate events: tracing-log is listed explicitly, so events from dependencies that use the log crate still reach the subscriber if default features are ever disabled.

Deploy note

The zero-token analytics error (Successful generative response recorded zero tokens) now records request_model/response_model as plain strings instead of Some("…"). This changes its compact output too. Before deploying, update any query that matches the old Some("…") form, and any that matches compact-only text such as WARN <span>:. Both formats can match during rollout, for example with request_model(?:=Some\(|":|=)"(?P<request_model>[^"\\]+)".

Tests

telemetry::tests::json_logging_writes_every_error_as_one_json_line runs the real initialization in a child process (it installs the global subscriber and panic hook). It checks that a tracing error with a multi-line field, a log-crate error and a panic each produce exactly one JSON line at ERROR, with fields at the top level and the span list present.

json_events_carry_their_spans_request_ids_at_the_top_level covers the request-ID lifting, and json_log_lines_carry_request_id_at_top_level checks it on a real chat completion through the router.

just lint rust and just test rust pass locally (4238 tests).

Refs DW-966

BEGIN_COMMIT_OVERRIDE
feat(telemetry): add JSON log format (#2044)
END_COMMIT_OVERRIDE