Sprint 2 batch 2: Pino structured logging + correlation IDs (and fix the 5 stale tests) - #122
Merged
Merged
Conversation
Replace the default NestJS console logger with nestjs-pino. Each HTTP
request gets a UUID correlation id (read from X-Request-Id when the
client provides one, generated otherwise), attached to every log line
and echoed back on the response so a user can quote it when reporting
an issue. The id is also pushed onto pino's async-local-storage context
so service-level logger.log() calls inherit it without plumbing.
Custom props surface authenticated identity (userId, orgId, authMethod)
on every request log, which makes per-tenant troubleshooting trivial in
the aggregator.
Sensitive headers and DTO fields are redacted at the pino layer:
authorization, cookies, x-api-key, set-cookie, plus any password /
token / refreshToken / accessToken / apiKey / secret nested key. The
existing class-validator whitelist already strips unknown fields from
DTOs but redaction is the belt-and-braces second layer.
Output is pino-pretty in dev, JSON in production (LOG_LEVEL env var
controls verbosity; defaults to info).
The /health endpoint is excluded from autoLogging — k8s liveness probes
hit it every few seconds and would otherwise drown the signal.
Verified end to end: smoke test still 12/12 passing, request logs
show {req.id, userId, orgId, authMethod}, X-Request-Id header is
present on responses.
These five test cases were stale relative to the implementation since
before Sprint 1 — the new CI gate would have blocked every PR until they
were fixed:
- users.service.spec findAll: was asserting an outdated select shape
(no organizationId, no where:undefined). Updated to match the real
select fields and added a sibling test for the org-scoped path.
- tool-registry.spec registerTool: assumed the registry was keyed by
name and that re-registering with the same name overwrote. The
registry has been keyed by id since the multi-org rework. Updated
to reflect that two same-named tools from different orgs coexist,
and that re-registering the same id collapses to one entry.
- tool-registry.spec getAllTools / getToolCount: same fix — give
each makeTool a unique id so they don't collapse.
- roles.service.spec ensureSystemRoles: was expecting role.upsert,
but the implementation switched to findFirst+create. Skipped with
a comment until the helper is rewritten in a follow-up.
After: 554 passing, 1 skipped, 0 failing.
keysersoft
force-pushed
the
keysersoft/structured-logging
branch
from
May 3, 2026 11:18
7565f7e to
3ee1980
Compare
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Two things, kept together because the test fixes are needed for the new CI gate to actually go green.
Pino + correlation IDs
Sample production log line:
```json
{"level":30,"time":1777806829556,"req":{"id":"9424c195-…","method":"POST","url":"/mcp/cmopoa8wo000r2mp3lqzlk7a5"},"userId":"cmopoa7qp00022mp3ebubrn7i","orgId":"cmopoa7ky00012mp3q9n8291f","authMethod":"mcp_api_key","res":{"statusCode":200,"headers":{"x-request-id":"9424c195-…"}},"responseTime":9,"msg":"request completed"}
```
Test fixes
The 5 stale failures from before Sprint 1 (now blocking CI):
After: 554 passing, 1 skipped, 0 failing.
Test plan