improvement(logs): move correlation ids from message tags into metadata and enforce it

Merged
WA
3d ago
+4152-3299

Summary

  • Log messages no longer carry correlation ids in their text. logger.info([${requestId}] Started) becomes logger.info('Started', { requestId }), so a message groups across requests and lines filter by requestId (or documentId, label, …) as a field. 1,937 tagged calls across 294 files moved by an AST codemod; the remaining forms (compound [${label}/phase] tags, ternary and const-built messages, prefix consts, helpers such as logFailureOnce(logger, message, …)) were moved by hand.
  • Inside withRouteHandler, a generateRequestId() id is the request context's id, which the logger already stamps on every line, so those tags are dropped without a field (per CLAUDE.md). Variables that existed only for the tag are deleted.
  • Code that minted its own id only to tag its lines (v1 routes, the poll routes, the table runners) now uses generateRequestId(), so it is the request's id; the poll routes' lock values and response requestId now equal the x-request-id header. Each webhook poll and each emitted Sim event keeps its own id, because executions use it as an idempotency key; each poll logs through a logger bound to its webhookId.
  • @sim/logger now owns requestId: inside a request context the context's id is authoritative, so a requestId passed with a line or bound with withMetadata cannot replace it (it names the request only outside a context), and an undefined field no longer erases a field the line already carries. Before, an explicit field could detach a line from its request: a replay key, a resumed run's original id, or an absent optional id replaced or deleted it. The JSON line now matches the OpenTelemetry export, which already took requestId from the context. v2 chat logs its Mothership request id as simRequestId, and ids that defaulted to 'unknown' default to generateRequestId().
  • check:source-conventions gains log-message-tag: it flags a @sim/logger message that opens with an interpolated tag (also after static tags like [Cascade]) or interpolates a request id anywhere. It covers every apps/* and packages/* module that imports @sim/logger, sees optional calls, computed levels and withMetadata-derived loggers, follows a message through concatenation, ternaries, function-scoped const/let bindings, log* helpers and .call(logger, …), and starts at zero, so the pattern cannot come back. Bracketed lists mid-message (columns [${ids.join(', ')}]) are allowed.
  • CLAUDE.md/AGENTS.md "Logging" and the add-trigger skill example describe the convention.

Type of Change

  • Improvement

Testing

  • check:source-conventions passes with log-message-tag 0; rule tests cover each flagged form and the allowed ones (42 pass).
  • Logger tests: the context id wins over a per-line or bound requestId, a per-line id applies outside a context, and an undefined field erases nothing; the two guard tests fail on the previous logger.
  • Ran the tests that assert on changed log lines plus the touched polling, tools, execution-core, credential, persistence, knowledge and webhook polling suites (about 900 tests); updated assertions to the new message and metadata shape, and rewrote one negative assertion that would otherwise have passed vacuously.
  • biome on all changed files; the full suite and type-check run in CI.

Checklist

  • Code follows project style guidelines
  • Self-reviewed my changes
  • Tests added/updated and passing (new tests pass the test-audit authoring gate)
  • No new warnings introduced
  • I confirm that I have read and agree to the terms outlined in the Contributor License Agreement (CLA)