Structured JSON logging with correlation IDs across request lifecycle - #1072
Merged
joelpeace48-cell merged 8 commits intoJul 29, 2026
Conversation
Framework-agnostic core (lib/requestContext.js) plus a thin Express adapter. Lets any code in a request or job's call chain read the current correlation ID without threading it through every function signature.
…sseStudioLab#925) pino mixin auto-injects requestId into every log line via the new context; redact config strips API keys/auth headers/passwords by convention. requestContextMiddleware mounted right after requestId in index.js. X-Request-Id added to CORS allowed/exposed headers so cross-origin clients can read and supply it. Adds the requestId.test.js unit coverage that didn't previously exist.
Both jobRunner (in-memory) and durableJobQueue (SQLite-backed) capture the enqueuing request's correlation ID and re-establish it as context when the job actually runs, so job logs — including retries — tie back to the request that triggered them. The durable queue persists the ID on the job row (migration 035) so it survives a process restart. Job logs switched from interpolated strings to structured objects.
…inesseStudioLab#925) rpcPool.js and sorobanRpc.js had zero logging before this. Adds structured log lines for circuit-breaker transitions, pool saturation, endpoint health changes, and RPC success/failure/latency, all correlated via the outbound x-request-id header and log context. Also fixes two compounding pre-existing bugs found via stricter typing on checkSorobanRpcHealth: routes/status.js called it with no rpcUrl (always fetching undefined) and treated its returned result object — always truthy, even on status: 'error' — as a boolean, so the status page permanently reported the RPC component as operational.
…log (FinesseStudioLab#925) log.X('message', {fields}) silently drops the fields object with pino's real argument order (fields first, message second) — verified empirically. Fixes ~26 such call sites across status.js, webhooks.js, faucet.js, and pruningJob.js, and migrates routes/variants.js and routes/audit.js off raw console.error onto the structured logger.
Integration-level coverage: X-Request-Id generation/echo/uniqueness, CORS exposure, and that the access-log line carries the same ID returned to the client.
…flict) PR_DESCRIPTION.md and pr_description.md were both tracked with the same content family, which is unrepresentable on case-insensitive filesystems and made every checkout/rebase spuriously dirty. Keeping only the uppercase path.
…-logging-correlation-ids # Conflicts: # backend/src/jobs/jobRunner.test.js
|
@Armolas Great news! 🎉 Based on an automated assessment of this PR, the linked Wave issue(s) no longer count against your application limits. You can now already apply to more issues while waiting for a review of this PR. Keep up the great work! 🚀 |
joelpeace48-cell
merged commit Jul 29, 2026
ba2fb96
into
FinesseStudioLab:main
4 of 15 checks passed
3 tasks
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
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
Closes #925. Pino was already wired up for structured JSON logging, and a
requestIdmiddleware already existed — but correlation IDs never made it past the access-log line into jobs, RPC calls, or business-logic logs, and there was no secret redaction at all. This PR closes those gaps.What's new
Correlation context
AsyncLocalStorage-based correlation context (backend/src/lib/requestContext.js) so any code in a request or job's call chain can read the current correlation ID without threading it through every function signature.mixin— everylog.*()call automatically picks uprequestIdfrom the active context, no call site needs to remember to pass it.X-Request-Idadded to CORS allowed/exposed headers so cross-origin clients can read and supply it.Propagation to jobs + RPC
jobRunner(in-memory) anddurableJobQueue(SQLite-backed) capture the enqueuing request's correlation ID and re-establish it as context when the job actually runs, so job logs — including retries — tie back to the request that triggered them.rpcPool.jsandsorobanRpc.jshad zero logging before this PR. Added structured log lines for circuit-breaker transitions, pool saturation, endpoint health changes, and RPC success/failure/latency — all correlated via the outboundx-request-idheader and log context.No secret leakage
redactconfig stripping API keys, auth headers, passwords, and tokens by convention (previously none existed).Cleanup (blocking "all logs are structured")
log.X('message', {fields})was silently dropping the fields object — pino's real argument order is(fields, message), verified empirically. Affectedstatus.js,webhooks.js,faucet.js,pruningJob.js.routes/variants.jsandroutes/audit.jsoff rawconsole.erroronto the structured logger.Bugs found along the way
Tightening
checkSorobanRpcHealth's typing (needed for correct test coverage) surfaced two compounding pre-existing bugs inroutes/status.js: it called the health check with norpcUrl(always fetchingundefined), and treated the returned result object — always truthy, even onstatus: 'error'— as a boolean. Net effect: the public status page's RPC component permanently reported "operational" regardless of actual health. Fixed both.Testing
~60 new/extended tests across
lib/requestContext,middleware/requestContext,middleware/requestId(previously untested),middleware/logger(mixin + redact verified against a real pino instance, not mocked),jobRunner,durableJobQueue,rpcPool,sorobanRpc, andindex.test.jsintegration tests.Live end-to-end smoke test: booted the real backend and confirmed a client-supplied
X-Request-Idheader shows up correlated across the access log, RPC log, and response headers; confirmed job retries share a consistent correlation ID across attempts; confirmed anAuthorizationheader never leaks into logs.eslint/tsc --noEmitclean on all touched files (pre-existing, unrelated warnings/errors elsewhere untouched).Acceptance criteria