decide: flatten the JSON log layer, or keep documenting the | json trap #27

Open
opened 2026-08-26 14:49:33 +00:00 by jlxq0 · 0 comments
Owner

Documented at 2089525 as a trap to work around. This issue exists so the alternative, removing the trap, is a decision with a state rather than a thing nobody raised.

The trap

src/main.rs:289 builds the JSON layer as fmt::layer().json(). That nests every event field under fields, so a line reads:

{"timestamp":"…","level":"INFO","fields":{"message":"…","user_hash":"f5a076c6a6c82848"},"target":"caldav_mcp"}

Loki's | json parser flattens that to fields_user_hash. A query filtering on user_hash therefore returns empty against lines that demonstrably exist, and an identity that never authenticated returns the identical empty set. The parser being unable to see the field and the field never having been written are the same result.

That cost an hour tonight and was recovered only by switching to regexp:

sum by (uh) (count_over_time({namespace="caldav-mcp"}
  | regexp `"user_hash":"(?P<uh>[0-9a-f]+)"` [14d]))

The one-line alternative

tracing_subscriber::fmt::format::Json::flatten_event exists (0.3.23, src/fmt/format/json.rs:100) and is reachable as:

fmt::layer().json().flatten_event(true)

Fields move to the top level, | json works directly, and the trap stops existing rather than being documented.

The trade, which is why this is an issue and not a commit

Against flattening:

  • Every existing Loki query, dashboard and alert keyed on fields_* breaks silently on the next deploy. Silently is the operative word: a broken query returns empty, which is the exact failure this change is meant to remove, arriving once during the cutover.
  • message moves to the top level and can collide with any field named message. Nothing here emits one, but nothing stops it either.
  • It is a log-format change to a service whose logs were the evidence base for two investigations today.

For flattening:

  • The trap is ours rather than Loki's. We emit the nesting; the parser is behaving correctly.
  • The mitigation currently costs every future reader a regexp they have to know to reach for, and the documentation only helps someone who already suspects the zero is wrong.
  • The cutover cost is one-time and knowable; the trap cost is per-reader and unbounded.

What would make this safe

Not the change on its own. Whoever takes it should find every fields_* query in Loki, Grafana and the alert rules first, since the failure mode of missing one is an empty result rather than an error. That is an operations sweep rather than a code edit, which is the actual size of this and the reason it is not a one-line PR.

Related: #20's observability work, which added the user_hash this was first noticed on.

Documented at `2089525` as a trap to work around. This issue exists so the alternative, removing the trap, is a decision with a state rather than a thing nobody raised. ## The trap `src/main.rs:289` builds the JSON layer as `fmt::layer().json()`. That nests every event field under `fields`, so a line reads: ```json {"timestamp":"…","level":"INFO","fields":{"message":"…","user_hash":"f5a076c6a6c82848"},"target":"caldav_mcp"} ``` Loki's `| json` parser flattens that to `fields_user_hash`. A query filtering on `user_hash` therefore **returns empty against lines that demonstrably exist**, and an identity that never authenticated returns the identical empty set. The parser being unable to see the field and the field never having been written are the same result. That cost an hour tonight and was recovered only by switching to `regexp`: ```logql sum by (uh) (count_over_time({namespace="caldav-mcp"} | regexp `"user_hash":"(?P<uh>[0-9a-f]+)"` [14d])) ``` ## The one-line alternative `tracing_subscriber::fmt::format::Json::flatten_event` exists (0.3.23, `src/fmt/format/json.rs:100`) and is reachable as: ```rust fmt::layer().json().flatten_event(true) ``` Fields move to the top level, `| json` works directly, and the trap stops existing rather than being documented. ## The trade, which is why this is an issue and not a commit **Against flattening:** - Every existing Loki query, dashboard and alert keyed on `fields_*` breaks silently on the next deploy. Silently is the operative word: a broken query returns empty, which is the exact failure this change is meant to remove, arriving once during the cutover. - `message` moves to the top level and can collide with any field named `message`. Nothing here emits one, but nothing stops it either. - It is a log-format change to a service whose logs were the evidence base for two investigations today. **For flattening:** - The trap is ours rather than Loki's. We emit the nesting; the parser is behaving correctly. - The mitigation currently costs every future reader a `regexp` they have to know to reach for, and the documentation only helps someone who already suspects the zero is wrong. - The cutover cost is one-time and knowable; the trap cost is per-reader and unbounded. ## What would make this safe Not the change on its own. Whoever takes it should find every `fields_*` query in Loki, Grafana and the alert rules first, since the failure mode of missing one is an empty result rather than an error. That is an operations sweep rather than a code edit, which is the actual size of this and the reason it is not a one-line PR. Related: `#20`'s observability work, which added the `user_hash` this was first noticed on.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
jlxq0/caldav-mcp#27
No description provided.