fix(observability): child-logger field-name drift across webhook handlers breaks per-entity log correlation

[chrisleekr]

Finding

src/logger.ts:218#createChildLogger defines the canonical contract for per-request structured log fields: { deliveryId, owner, repo, entityNumber }. The doc comment at src/logger.ts:215 explicitly promises "Consistent fields across all log lines for a single request." In practice every webhook event handler bypasses this helper and calls logger.child(...) directly with a hand-rolled field set, and the entity-identifier field name drifts across five handlers and two executors. As a result an operator who knows a PR or issue number cannot grep one field name to reconstruct a request end-to-end, the very correlation property the Observability doc page advertises in its first paragraph.

Concrete drift, verified by reading each file at HEAD (f2f9f46):

• src/webhook/events/issues.ts:69 emits issueNumber on issues.labeled.
• src/webhook/events/pull-request.ts:148 emits prNumber on pull_request.labeled.
• src/webhook/events/issue-comment.ts:48 emits issueNumber even when payload.issue.pull_request !== undefined (the comment is actually on a PR, computed one line later at src/webhook/events/issue-comment.ts:69 as isPR), so the same numeric entity flips field name between issues.labeled and pull_request.labeled depending on the trigger surface.
• src/webhook/events/review-comment.ts:56 emits prNumber.
• src/daemon/job-executor.ts:314 is the one site that uses createChildLogger correctly and emits entityNumber.
• src/daemon/workflow-executor.ts:60 nests the number inside a target object (target.number), a third shape entirely.

A second, orthogonal gap rides on the same call sites: every event handler captures payload.installation.id into a local installationId (src/webhook/events/issue-comment.ts:64, src/webhook/events/review-comment.ts:93, src/webhook/events/issues.ts:94, src/webhook/events/pull-request.ts:109) and threads it into downstream ship pr.installation_id payloads, but never attaches it to the child logger. Multi-tenant operators cannot filter logs by GitHub installation, which is the natural unit of REST/GraphQL rate-limit accounting. The docs/operate/observability.md:19-34 "Common log fields" table reflects the gap, it lists deliveryId, event, repo, dispatch_target, etc., but no field for the entity number or the installation.

The minimal fix is to extend createChildLogger (src/logger.ts:218) with an optional installationId?: number and a discriminator so callers continue to pass either prNumber or issueNumber semantically while the helper writes a single canonical entityNumber (plus the original semantic name for backwards-compat log queries during a transition window), then migrate the six bypass sites to it. The daemon workflow-executor.ts nested target can stay (it's the workflow envelope) but must additionally write a flat entityNumber so per-entity grep aligns with the rest of the fleet. Add a row for the new fields to docs/operate/observability.md:19-34.

Diagram

flowchart LR
  classDef webhook fill:#1f4e79;color:#ffffff
  classDef daemon fill:#196f3d;color:#ffffff
  classDef canonical fill:#7a5800;color:#ffffff
  classDef drift fill:#922b21;color:#ffffff

  WH[Webhook receiver<br/>deliveryId stable]:::webhook

  ISS[events/issues.ts L69<br/>field: issueNumber]:::drift
  PRL[events/pull-request.ts L148<br/>field: prNumber]:::drift
  ICM[events/issue-comment.ts L48<br/>field: issueNumber]:::drift
  RCM[events/review-comment.ts L56<br/>field: prNumber]:::drift

  JE[daemon/job-executor.ts L314<br/>field: entityNumber]:::canonical
  WE[daemon/workflow-executor.ts L60<br/>field: target.number nested]:::drift

  CCL[logger.ts L218<br/>createChildLogger contract<br/>entityNumber]:::canonical

  WH --> ISS
  WH --> PRL
  WH --> ICM
  WH --> RCM

  ISS --> JE
  PRL --> JE
  ICM --> JE
  RCM --> JE

  JE --> WE

  CCL -.canonical.-> JE
  CCL -.bypassed.-> ISS
  CCL -.bypassed.-> PRL
  CCL -.bypassed.-> ICM
  CCL -.bypassed.-> RCM
  CCL -.bypassed.-> WE

Loading

Rationale

The deliveryId correlation chain works end-to-end (one field, threaded through BotContext.deliveryId from webhook to daemon), and the operator-facing observability doc leans on this property: "Every dispatch decision and every pipeline step carries a deliveryId so you can reconstruct a request end-to-end from a single log query" (docs/operate/observability.md:3). The entity-number chain does not work this way. Two real operator workflows break:

1. Per-entity post-mortem. An on-call sees a flapping PR (say #42 in chrisleekr/foo) and wants every log line for it across a week. With current drift the query has to be (prNumber:42 OR issueNumber:42 OR target.number:42 OR entityNumber:42) AND repo:"chrisleekr/foo". That is four OR branches against a structured store (Loki / Datadog) that bills per-query bytes scanned, and any site added in the future drifts again.
2. Per-installation tenancy / rate-limit triage. The CLAUDE.md "Authentication options" section makes per-installation isolation a first-class concept (ALLOWED_OWNERS single-tenant gate), and the App's rate-limit bucket is per-installation. When a secondary-rate-limit 403 fires from GitHub there is no installation_id field on the surrounding log lines to scope the blast radius, even though payload.installation.id is available at every webhook entry point.

Both fixes are byte-cheap (one extra field per child-logger creation, ~50 LOC across the seven call sites plus a createChildLogger signature widening), have no runtime cost (pino child loggers fold mixins at log-time), and stay within the existing pino architecture, no new dependency. They unlock the correlation guarantee the doc already advertises.

This matches the pino child() documentation pattern (child loggers exist precisely to bind stable request-scoped fields once) and aligns the codebase with the OpenTelemetry semantic-conventions principle that the same attribute key should denote the same concept across emitters in a single service.

References

Internal:

• src/logger.ts:218#createChildLogger (canonical contract, entityNumber).
• src/webhook/events/issues.ts:69 (issueNumber).
• src/webhook/events/pull-request.ts:148 (prNumber).
• src/webhook/events/issue-comment.ts:48 (issueNumber even for PR comments, see isPR at src/webhook/events/issue-comment.ts:69).
• src/webhook/events/review-comment.ts:56 (prNumber).
• src/daemon/job-executor.ts:314 (canonical helper used here).
• src/daemon/workflow-executor.ts:60 (target.number, nested).
• src/webhook/events/issue-comment.ts:64, src/webhook/events/review-comment.ts:93 (installation id captured but not logged).
• docs/operate/observability.md:3 (correlation promise) and docs/operate/observability.md:17 (Common log fields table missing entity-number + installation rows).

External:

• pino child() docs — child loggers are the supported pattern for stable per-request fields.
• OpenTelemetry semantic conventions: General log attributes — cross-signal naming consistency principle.
• Better Stack: pino guide — production pattern for correlation IDs.
• GitHub REST API rate-limit docs — rate-limit accounting is per-installation; logs need that key.

Suggested Next Steps

1. Widen createChildLogger in src/logger.ts:218 to accept installationId?: number and a discriminator for the entity kind (isPR: boolean), and have it emit entityNumber: number as the canonical field plus installationId (omitted via exactOptionalPropertyTypes when absent).
2. Migrate the five webhook event handlers (issues.ts, pull-request.ts, issue-comment.ts, review-comment.ts, review.ts) to call createChildLogger instead of logger.child. Keep the prior prNumber / issueNumber field for one release as a compatibility-during-transition mirror, then remove in a follow-up.
3. Update src/daemon/workflow-executor.ts:60 to add a flat entityNumber alongside the existing nested target object so the canonical grep aligns. Do not remove target (it's the workflow envelope).
4. Add a new row to the "Common log fields" table in docs/operate/observability.md:19-34 for entityNumber and installationId, and update the lede paragraph at docs/operate/observability.md:3 so the correlation promise covers entity-scoped queries too.
5. Add a small test in src/logger.test.ts (or co-located) that round-trips a createChildLogger output through a pino capture and asserts entityNumber + installationId are emitted on the resulting line, mirroring the schema-pinning pattern used at src/workflows/ship/log-fields.ts.

Areas Evaluated

Read src/logger.ts end-to-end (root logger, redaction lists, errSerializer, createChildLogger). Surveyed every logger.child(...) and createChildLogger(...) call site under src/ via Grep (51 files, 264 logger.<level> call sites, 17 child-logger creation sites). Cross-checked the field names against docs/operate/observability.md "Common log fields" table. Sampled the daemon executors (job-executor.ts, workflow-executor.ts, scheduled-action-executor.ts, scoped-*-executor.ts) for downstream field consistency. Reviewed existing area: observability research issues to confirm non-overlap with: periodic fleet-state gauge, stdio-MCP-server pino logger, octokit rate-limit hook, pipeline.stage events with delta_ms, pino.final on uncaught/unhandled. None of those touch the per-handler field-name drift surfaced here.

Generated by the scheduled research action on 2026-05-28

[chrisleekr]

Starting work on this issue.

Validation (confirmed against HEAD 247f5ce)

Confirmed the drift: createChildLogger (src/logger.ts:218) defines the canonical {deliveryId, owner, repo, entityNumber} contract and is already used by app.ts:292, core/context.ts:21/59, and daemon/job-executor.ts:314 — but the webhook handlers bypass it and hand-roll the entity field:

• issues.ts:76 → issueNumber
• pull-request.ts:155 → prNumber
• issue-comment.ts:52 → issueNumber (even for PR-backed comments)
• review-comment.ts:60 → prNumber
• daemon/workflow-executor.ts:60 → nested target.number only (no flat field)

So an operator cannot grep one field name to reconstruct a request across handlers. Valid.

Approach

1. Widen createChildLogger to accept the 4 required canonical fields plus arbitrary extra bindings (& Record<string, unknown>), so handlers route through the single source of truth while keeping their extras (event, label, senderLogin). Existing 4-field callers are unaffected.
2. Migrate the 4 webhook handlers to createChildLogger, emitting the entity id as canonical entityNumber.
3. workflow-executor.ts:60: add a flat entityNumber alongside the nested target (keep target — it is the workflow envelope), per the issue.
4. review.ts: add entityNumber to its logger.debug binding (it currently emits no entity id at all, so review events are ungreppable by PR number).
5. Docs: add an entityNumber row to the "Common log fields" table in docs/operate/observability.md and extend the lede to cover entity-scoped correlation.
6. Test: extend test/utils/logger.test.ts to round-trip createChildLogger through a pino capture and assert entityNumber + extra-field passthrough.

Judgement calls (deviations from the issue’\s proposed-fix wishlist)

• No prNumber/issueNumber compatibility mirror. The proposal suggested keeping the old names for one release then removing in a follow-up. I verified nothing consumes those field names — zero references in docs/, no dashboards, no alerts (grep clean). A mirror would add tech debt and spawn a needless follow-up issue for zero benefit, so I migrate cleanly. This also makes the proposed isPR discriminator in the helper unnecessary (it only existed to drive the mirror).
• installationId descoped. The proposal bundled adding installationId. That is a separate correlation enhancement, not the stated field-name-drift bug, and it interacts with installation-guard ordering in some handlers (the child logger is built before the payload.installation === undefined guard). The stated bug — per-entity correlation under one field name — is fully fixed by the entityNumber migration alone. Can be a focused follow-up.
• Job-queue schema untouched. The prNumber/issueNumber fields in ws-messages.ts / job-queue.ts / job-dispatcher.ts are the job-payload contract, not per-request correlation bindings, and were not cited by the Finding. Renaming them would be an unrelated breaking change. Out of scope.