Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 22 additions & 3 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,19 @@ coverage/
.nyc_output/
stryker-tmp/

# Test snapshots
**/__snapshots__/
*.snap

# Pact generated files (keep .gitkeep, ignore generated JSONs)
pacts/*.json

# Scratch / local experiments
scratch/

# Pull request bundles / local PR artifacts
.pull_request/

# Logs
*.log
pact.log
Expand All @@ -34,9 +47,7 @@ pact.log
.vscode/settings.json

# Kiro
.kiro/


.kilo/

# Load test output
tests/load/results/*.json
Expand All @@ -48,3 +59,11 @@ benchmarks/results/*.json
.cache/

secret.yaml

# Playwright test artifacts
test-results/
playwright-report/

# Stryker mutation testing output
.stryker-tmp/
reports/mutation/
2 changes: 2 additions & 0 deletions src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,7 @@ import {
import { requireAuth } from "./middleware/auth";
import { responseTime } from "./middleware/responseTime";
import { requestId } from "./middleware/requestId";
import { correlationIdMiddleware } from "./middleware/correlationId";
import { readReplicaRoutingMiddleware } from "./middleware/readReplicaRouting";
import { dbConnectionLeakDetector } from "./middleware/dbConnectionLeakDetector";
import { i18nMiddleware } from "./utils/i18n";
Expand Down Expand Up @@ -173,6 +174,7 @@ app.use(
// app.use(rateLimitMiddleware);
app.use(responseTime);
app.use(requestId);
app.use(correlationIdMiddleware);
app.use(readReplicaRoutingMiddleware);
app.use(i18nMiddleware);
app.use(dbConnectionLeakDetector);
Expand Down
81 changes: 81 additions & 0 deletions src/middleware/correlationId.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
/**
* Correlation ID Middleware — issue #260
*
* Generates or propagates a correlation ID for every incoming request so that
* a single transaction can be traced across:
* - Express HTTP handlers
* - BullMQ / RabbitMQ queue workers
* - Provider callback handlers
* - Structured log lines
*
* Priority order for ID selection:
* 1. x-correlation-id — set by upstream gateways / load balancers
* 2. x-trace-id — legacy header (still honoured for backward compat)
* 3. x-request-id — set by the existing requestId middleware
* 4. crypto.randomUUID() — generated fresh when none of the above are present
*
* The resolved ID is:
* - Written back onto req.correlationId (typed via express-augment.d.ts)
* - Echoed in the X-Correlation-ID response header so clients can
* reference it in support tickets
* - Attached to every log line via a child logger bound to the calling
* request (see logger.ts childLogger)
*
* No duplicate tracking: if `x-correlation-id` is already set upstream it is
* reused as-is, preventing extra IDs from being minted for the same logical
* request.
*
* Performance: the middleware does nothing heavier than a UUID v4 generation
* (~1 µs) and a header read/write — well within the < 1% budget.
*/

import { randomUUID } from "crypto";
import { Request, Response, NextFunction } from "express";
import { childLogger } from "../utils/logger";

/** The canonical incoming header name (lowercase, as Node normalises them). */
export const CORRELATION_ID_HEADER = "x-correlation-id";

/** Response header echoed back to callers. */
export const CORRELATION_ID_RESPONSE_HEADER = "X-Correlation-ID";

/**
* Resolves the correlation ID from the incoming request headers.
* Returns a new UUID if none of the known trace headers are present.
*/
export function resolveCorrelationId(req: Request): string {
return (
(req.headers[CORRELATION_ID_HEADER] as string | undefined) ??
(req.headers["x-trace-id"] as string | undefined) ??
(req.headers["x-request-id"] as string | undefined) ??
randomUUID()
);
}

/**
* Express middleware that attaches a correlation ID to every request.
*
* After this middleware runs:
* - `req.correlationId` is set to the resolved ID
* - `req.log` is set to a child logger pre-bound with `{ correlation_id }`
* - The `X-Correlation-ID` response header is written
*/
export function correlationIdMiddleware(
req: Request,
res: Response,
next: NextFunction,
): void {
const correlationId = resolveCorrelationId(req);

// Attach to request for downstream handlers and services
(req as Request & { correlationId: string }).correlationId = correlationId;

// Provide a bound child logger so handlers can log with the ID automatically
(req as Request & { log: ReturnType<typeof childLogger> }).log =
childLogger(correlationId, { correlation_id: correlationId });

// Echo back so clients and API gateways can correlate their own traces
res.setHeader(CORRELATION_ID_RESPONSE_HEADER, correlationId);

next();
}
13 changes: 10 additions & 3 deletions src/middleware/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -78,13 +78,20 @@ export function requestLogger(
const durationNs = process.hrtime.bigint() - start;
const responseTimeMs = Number(durationNs) / 1e6;

// Propagate trace_id from the incoming request header when available so
// all log lines for a single request share the same distributed trace id.
// Propagate correlation_id / trace_id from the request so all log lines
// for a single request share the same distributed trace context.
// Priority: correlationId set by correlationId middleware (which already
// resolved x-correlation-id > x-trace-id > x-request-id) — then fall
// back to the raw headers for requests that bypass the middleware.
const traceId =
(req as Request & { correlationId?: string }).correlationId ??
(req.headers["x-correlation-id"] as string | undefined) ??
(req.headers["x-trace-id"] as string | undefined) ??
(req.headers["x-request-id"] as string | undefined);

const reqLogger = traceId ? childLogger(traceId) : logger;
const reqLogger = traceId
? childLogger(traceId, { correlation_id: traceId })
: logger;

reqLogger.info({
event: { dataset: "http.request" },
Expand Down
60 changes: 40 additions & 20 deletions src/queue/trace.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,16 @@
/**
* Trace-ID propagation for queue workers.
* Trace-ID / Correlation-ID propagation for queue workers — issue #260
*
* Ensures that a trace ID generated (or received) at the HTTP edge is carried
* through every queue job so that worker logs can be correlated back to the
* originating request.
* Ensures that a correlation ID generated (or received) at the HTTP edge is
* carried through every queue job so that worker logs can be correlated back
* to the originating request in a single search query.
*
* Usage — enqueue side (e.g. inside a route handler or service):
* Supported ID headers (priority order, highest first):
* 1. x-correlation-id — canonical header written by correlationId middleware
* 2. x-trace-id — legacy distributed-trace header
* 3. x-request-id — original request-id header
*
* Usage — enqueue side (inside a route handler or service):
* import { withTraceId } from "../queue/trace";
* await addTransactionJob(withTraceId(req, { transactionId, ... }));
*
Expand All @@ -17,33 +22,41 @@

import { childLogger } from "../utils/logger";

/** The key used inside job data objects to carry the trace ID. */
/** Key stored in job data to carry the correlation / trace ID. */
export const TRACE_ID_KEY = "_traceId" as const;

/**
* Returns a shallow copy of `data` with the trace ID extracted from the
* incoming HTTP request appended. If no trace header is present, a random
* UUID is generated so every job is still traceable.
* Returns a shallow copy of `data` with the correlation ID extracted from the
* incoming HTTP request appended. Priority: x-correlation-id > x-trace-id >
* x-request-id > req.correlationId > new UUID.
*
* `req` should be an Express Request (or any object with a `headers` map).
* It is typed loosely to avoid a hard dependency on `express` types.
* `req` is typed loosely to avoid a hard dependency on express types and to
* allow usage from non-Express contexts (e.g. provider callback handlers).
*/
export function withTraceId<T extends Record<string, unknown>>(
req: { headers: Record<string, string | string[] | undefined> } | undefined,
req:
| {
headers?: Record<string, string | string[] | undefined>;
correlationId?: string;
}
| undefined,
data: T,
): T & { [TRACE_ID_KEY]: string } {
const traceId =
(req?.headers["x-trace-id"] as string | undefined) ??
(req?.headers["x-request-id"] as string | undefined) ??
(req?.headers?.["x-correlation-id"] as string | undefined) ??
(req?.headers?.["x-trace-id"] as string | undefined) ??
(req?.headers?.["x-request-id"] as string | undefined) ??
req?.correlationId ??
crypto.randomUUID();

return { ...data, [TRACE_ID_KEY]: traceId };
}

/**
* Extracts the trace ID from a job data object (BullMQ `job.data` or
* RabbitMQ message payload). Returns `undefined` when the job was enqueued
* before trace propagation was added.
* Extracts the trace / correlation ID from a job data object (BullMQ
* `job.data` or RabbitMQ message payload). Returns `undefined` when the job
* was enqueued before trace propagation was added so callers can fall back
* gracefully.
*/
export function traceIdFromJob(
data: Record<string, unknown> | undefined,
Expand All @@ -54,12 +67,19 @@ export function traceIdFromJob(
}

/**
* Creates a child logger pre-bound to the trace ID carried by the job.
* Falls back to the root logger when no trace ID is present.
* Creates a child logger pre-bound to the trace / correlation ID carried by
* the job data. The returned logger emits `correlation_id` and `trace_id` on
* every line so Loki / Grafana queries can filter across HTTP and queue layers
* with a single label.
*
* Falls back to `undefined` when no trace ID is present — callers should use
* the root logger in that case.
*/
export function childLoggerWithTrace(
data: Record<string, unknown> | undefined,
) {
const traceId = traceIdFromJob(data);
return traceId ? childLogger(traceId) : undefined;
if (!traceId) return undefined;
// Emit both keys so existing dashboards using trace_id continue to work
return childLogger(traceId, { correlation_id: traceId });
}
5 changes: 5 additions & 0 deletions src/types/express-augment.d.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
import 'express';
import type { Logger } from 'pino';

declare global {
namespace Express {
Expand All @@ -18,6 +19,10 @@ declare global {
geoLocation?: unknown;
userRole?: string;
locale?: string;
/** Correlation ID propagated from upstream or generated fresh per-request. */
correlationId?: string;
/** Child logger pre-bound with the request's correlation_id. */
log?: Logger;
}
}
}
Expand Down
Loading
Loading