Skip to content

feat(telemetry): add JSON log format - #2044

Merged
tobydigz merged 6 commits into
mainfrom
feat/dw-966/structured-logging
Oct 21, 2026
Merged

tobydigz merged 6 commits into
mainfrom
feat/dw-966/structured-logging

Conversation

@tobydigz

@tobydigz tobydigz commented Oct 20, 2026 •

Copy link
Copy Markdown
Contributor

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

View guided diff Turn on auto-fix

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

Compact log lines can only be searched by matching their text, so fields
cannot be queried directly, multi-line errors split across lines, and any
query that matches the line text is tied to how events happen to print.
`log_format: json` (DWCTL_LOG_FORMAT) writes one JSON object per event,
fields at the top level and the span list under `spans`. `compact` stays the
default.

Switching formats must not lose error logs, so:

- In JSON mode a panic is written to stderr as one JSON error line. The
  hook writes it directly instead of emitting a tracing event, which a
  RUST_LOG directive or a panic inside the subscriber could drop.
- A config that fails to load is logged in the format it asks for, when
  log_format can still be read from it, and a server exiting with an error
  logs it before exiting.
- Telemetry now starts before batch config validation, whose error was
  emitted before any subscriber existed and so was never written.
- tracing-log is listed explicitly so log-crate events from dependencies
  keep reaching the subscriber if default features are ever turned off.

The zero-token analytics error now records request_model and
response_model as plain strings rather than Debug-formatted Options, so
they read as values in either format. Queries that matched the old
`Some("...")` form need updating before this is deployed.

Refs DW-966
@cloudflare-workers-and-pages

cloudflare-workers-and-pages Bot commented Oct 20, 2026 •

Copy link
Copy Markdown

Deploying control-layer with  Cloudflare Pages  Cloudflare Pages

Latest commit: 33d82c5
Status: ✅  Deploy successful!
Preview URL: https://585b996c.control-layer.pages.dev
Branch Preview URL: https://feat-dw-966-structured-loggi.control-layer.pages.dev

View logs

@cubic-dev-ai cubic-dev-ai Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All reported issues were addressed across 11 files

Reply with feedback, questions, or to request a fix.

View guided diff | Turn on auto-fix | Re-trigger cubic

Comment thread docs/src/reference/configuration.md Outdated
Comment thread dwctl/src/main.rs Outdated
Comment thread dwctl/src/telemetry.rs Outdated
Comment thread dwctl/src/telemetry.rs
Review follow-ups for the JSON log format:

- main reports the error dwctl exits with once, through tracing when
  logging is up, and exits nonzero. Returning it from main also printed it
  as plain `Error: ...` lines beside the JSON line.
- Logging is installed before the OTLP exporter is built, so an exporter
  setup error is reported in the configured format, and the `[OTLP]`
  startup prints become fields on the initialization event.
- Panic lines carry the `span` and `spans` the panic happened in, as
  events do, so a panic can be tied to the request that caused it.
- The docs no longer claim compact output is one line per event.

Refs DW-966

@cubic-dev-ai cubic-dev-ai Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All reported issues were addressed across 3 files (changes from recent commits).

Reply with feedback, questions, or to request a fix.

View guided diff | Turn on auto-fix | Re-trigger cubic

Comment thread docs/src/reference/configuration.md Outdated
…d-logging

# Conflicts:
#	dwctl/src/request_logging/analytics_handler.rs
In JSON mode span fields only appear inside the `spans` array, which
Loki's `json` parser does not look into, so the request ID could no
longer be used as a key:value lookup. Services downstream of dwctl
already log the same ID as a top-level `x_request_id`.

A small layer records each span's correlation fields (x_request_id,
edge_request_id, provider_request_id, trace_id), and the JSON formatter
repeats them at the top level of every event inside that span, the
innermost value winning and an event's own field taking precedence.
Panic lines carry them too. The analytics handler, which runs after the
response and outside the request span, now records the request's
x_request_id on its own span so its errors can be found the same way.

One query now finds a request across dwctl and the services it calls:
`|= "<id>" | json | x_request_id="<id>"`.

Refs DW-966

@cubic-dev-ai cubic-dev-ai Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All reported issues were addressed across 6 files (changes from recent commits).

Reply with feedback, questions, or to request a fix.

View guided diff | Turn on auto-fix | Re-trigger cubic

Comment thread docs/src/reference/configuration.md Outdated
Only x_request_id is on every request line. edge_request_id, trace_id
and provider_request_id appear once known, and a panic outside every span
or inside the subscriber has no span context.

Refs DW-966

@cubic-dev-ai cubic-dev-ai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

0 issues found across 1 file (changes from recent commits).

Auto-approved: Adds opt-in JSON log format for dwctl telemetry with compact remaining the default; changes are confined to logging/telemetry setup, config parsing, docs, and analytics field formatting, with no effect on request handling or spend. The change is bounded and revertible.

View guided diff | Turn on auto-fix | Re-trigger cubic

@tobydigz
tobydigz added this pull request to the merge queue Oct 21, 2026
Merged via the queue into main with commit 1e87af0 Oct 21, 2026
27 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants