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
15 changes: 5 additions & 10 deletions src/middleware/logging.ts
Original file line number Diff line number Diff line change
Expand Up @@ -41,16 +41,11 @@ export const logger = pino(structuredLoggerOptions);
const TRUST_PROXY = process.env.TRUST_PROXY_HEADERS === 'true';

export function requestLogger(req: Request, res: Response, next: NextFunction): void {
// Prefer the sanitized ID already set by requestIdMiddleware (req.id).
// Fall back to the raw header value for contexts where requestIdMiddleware
// hasn't run (e.g. isolated unit tests), and finally generate a UUID.
const reqWithId = req as Request & { id?: string };
const requestId =
req.id ||
(Array.isArray(req.headers['x-request-id'])
? req.headers['x-request-id'][0]
: req.headers['x-request-id']) ||
uuidv4();
// Prefer the safely generated ID already set by requestIdMiddleware (req.id).
// Fall back to generating a new UUID for contexts where requestIdMiddleware
// hasn't run (e.g., isolated unit tests). We strictly avoid reading the raw
// x-request-id header here to prevent unsanitized IDs or PII from entering logs.
const requestId = req.id || uuidv4();

res.setHeader('x-request-id', requestId);

Expand Down
107 changes: 34 additions & 73 deletions src/middleware/requestId.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,21 +3,23 @@ import type { Request, Response, NextFunction } from 'express';
import { getRequestId } from '../logger.js';
import { requestIdMiddleware, sanitizeRequestId, REQUEST_ID_MAX_LENGTH } from './requestId.js';

const VALID_UUID = '123e4567-e89b-12d3-a456-426614174000';

describe('sanitizeRequestId', () => {
test('returns the value unchanged for a normal id', () => {
assert.equal(sanitizeRequestId('trace-abc-123'), 'trace-abc-123');
test('returns the value unchanged for a valid UUID', () => {
assert.equal(sanitizeRequestId(VALID_UUID), VALID_UUID);
});

test('trims surrounding whitespace', () => {
assert.equal(sanitizeRequestId(' test-trim-id '), 'test-trim-id');
test('trims surrounding whitespace and accepts valid UUID', () => {
assert.equal(sanitizeRequestId(` ${VALID_UUID} `), VALID_UUID);
});

test('strips CR and LF to prevent header injection', () => {
assert.equal(sanitizeRequestId('id\r\nX-Evil: injected'), 'idX-Evil: injected');
test('returns undefined for non-UUID string', () => {
assert.equal(sanitizeRequestId('trace-abc-123'), undefined);
});

test('strips all ASCII control characters', () => {
assert.equal(sanitizeRequestId('id\x00\x01\x1F\x7F'), 'id');
test('returns undefined for UUID with injected malicious characters', () => {
assert.equal(sanitizeRequestId(`${VALID_UUID}\r\nX-Evil: injected`), undefined);
});

test('returns undefined for empty string', () => {
Expand All @@ -33,39 +35,34 @@ describe('sanitizeRequestId', () => {
});

test('returns undefined when value exceeds REQUEST_ID_MAX_LENGTH', () => {
const oversized = 'a'.repeat(REQUEST_ID_MAX_LENGTH + 1);
const oversized = VALID_UUID + 'a';
assert.equal(sanitizeRequestId(oversized), undefined);
});

test('accepts value exactly at REQUEST_ID_MAX_LENGTH', () => {
const maxLen = 'a'.repeat(REQUEST_ID_MAX_LENGTH);
assert.equal(sanitizeRequestId(maxLen), maxLen);
});
});

describe('requestId middleware', () => {
test('uses incoming x-request-id header as request id and response header', (done) => {
test('uses incoming x-request-id header if it is a valid UUID', (done) => {
const req = {
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? 'test-id-123' : undefined),
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? VALID_UUID : undefined),
} as unknown as Request;

const res = {
setHeader: (name: string, value: string) => {
assert.equal(name, 'X-Request-Id');
assert.equal(value, 'test-id-123');
assert.equal(value, VALID_UUID);
},
} as unknown as Response;

const next = (() => {
assert.equal((req as any).id, 'test-id-123');
assert.equal(getRequestId(), 'test-id-123');
assert.equal((req as any).id, VALID_UUID);
assert.equal(getRequestId(), VALID_UUID);
done();
}) as NextFunction;

requestIdMiddleware(req, res, next);
});

test('generates a UUID request id when header is absent and sets it on response', (done) => {
test('generates a new UUID request id when header is absent', (done) => {
const req = {
header: () => undefined,
} as unknown as Request;
Expand All @@ -83,7 +80,7 @@ describe('requestId middleware', () => {
assert.ok(setHeaderValue, 'response X-Request-Id must be set');
assert.equal((req as any).id, setHeaderValue);

const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
assert.match(setHeaderValue ?? '', uuidRegex);
assert.match((req as any).id, uuidRegex);
assert.equal(getRequestId(), (req as any).id);
Expand All @@ -94,82 +91,46 @@ describe('requestId middleware', () => {
requestIdMiddleware(req, res, next);
});

test('strips whitespace from x-request-id header before using it', (done) => {
test('generates a new UUID when header is not a valid UUID (e.g. contains PII)', (done) => {
const req = {
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? ' test-trim-id ' : undefined),
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? 'john.doe@example.com' : undefined),
} as unknown as Request;

let setHeaderValue: string | undefined;

const res = {
setHeader: (_name: string, value: string) => {
assert.equal(value, 'test-trim-id');
setHeaderValue = value;
},
} as unknown as Response;

const next = (() => {
assert.equal((req as any).id, 'test-trim-id');
done();
}) as NextFunction;

requestIdMiddleware(req, res, next);
});

test('generates a UUID when header contains only control characters', (done) => {
const req = {
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? '\r\n\x00' : undefined),
} as unknown as Request;

let setHeaderValue: string | undefined;
const res = {
setHeader: (_name: string, value: string) => { setHeaderValue = value; },
} as unknown as Response;

const next = (() => {
const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
assert.match(setHeaderValue ?? '', uuidRegex);
done();
}) as NextFunction;

requestIdMiddleware(req, res, next);
});

test('generates a UUID when header value exceeds max length', (done) => {
const oversized = 'x'.repeat(REQUEST_ID_MAX_LENGTH + 1);
const req = {
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? oversized : undefined),
} as unknown as Request;
assert.notEqual(setHeaderValue, 'john.doe@example.com');
assert.notEqual((req as any).id, 'john.doe@example.com');

let setHeaderValue: string | undefined;
const res = {
setHeader: (_name: string, value: string) => { setHeaderValue = value; },
} as unknown as Response;

const next = (() => {
// Must not echo the oversized value back
assert.notEqual(setHeaderValue, oversized);
const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
assert.match(setHeaderValue ?? '', uuidRegex);
assert.match((req as any).id, uuidRegex);

done();
}) as NextFunction;

requestIdMiddleware(req, res, next);
});

test('strips CRLF injection attempt and uses sanitized value', (done) => {
// After stripping control chars the remaining value is non-empty, so it should be used.
test('strips whitespace from valid UUID before using it', (done) => {
const req = {
header: (name: string) =>
name.toLowerCase() === 'x-request-id' ? 'safe-id\r\nX-Evil: injected' : undefined,
header: (name: string) => (name.toLowerCase() === 'x-request-id' ? ` ${VALID_UUID} ` : undefined),
} as unknown as Request;

let setHeaderValue: string | undefined;
const res = {
setHeader: (_name: string, value: string) => { setHeaderValue = value; },
setHeader: (_name: string, value: string) => {
assert.equal(value, VALID_UUID);
},
} as unknown as Response;

const next = (() => {
assert.equal(setHeaderValue, 'safe-idX-Evil: injected');
assert.ok(!setHeaderValue?.includes('\r'));
assert.ok(!setHeaderValue?.includes('\n'));
assert.equal((req as any).id, VALID_UUID);
done();
}) as NextFunction;

Expand Down
17 changes: 9 additions & 8 deletions src/middleware/requestId.ts
Original file line number Diff line number Diff line change
Expand Up @@ -6,21 +6,22 @@ const REQUEST_ID_HEADER = 'x-request-id';

/**
* Maximum byte length accepted for a client-supplied X-Request-Id value.
* Anything longer is discarded and a fresh UUID is generated instead.
* 128 chars comfortably covers UUID v4 (36), ULID (26), and common trace-id formats.
* We restrict this to 36 characters to strictly allow only UUIDs.
*/
export const REQUEST_ID_MAX_LENGTH = 128;
export const REQUEST_ID_MAX_LENGTH = 36;

const UUID_REGEX = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;

/**
* Sanitise a raw header value so it is safe to echo back in a response header.
* - Strips ASCII control characters (including CR/LF) to prevent header injection.
* - Trims surrounding whitespace.
* - Returns undefined when the result is empty or exceeds REQUEST_ID_MAX_LENGTH.
* - Only accepts valid UUID strings.
* - Trims surrounding whitespace before validation.
* - Returns undefined when the result is not a valid UUID.
*/
export const sanitizeRequestId = (raw: string | undefined): string | undefined => {
if (!raw) return undefined;
const sanitized = raw.replace(/[\x00-\x1F\x7F]/g, '').trim();
if (!sanitized.length || sanitized.length > REQUEST_ID_MAX_LENGTH) return undefined;
const sanitized = raw.trim();
if (!UUID_REGEX.test(sanitized)) return undefined;
return sanitized;
};

Expand Down
138 changes: 138 additions & 0 deletions tests/integration/requestIdPropagation.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,138 @@
import express from 'express';
import request from 'supertest';
import { requestIdMiddleware } from '../../src/middleware/requestId.js';
import { requestLogger, logger as pinoLogger } from '../../src/middleware/logging.js';
import { errorHandler } from '../../src/middleware/errorHandler.js';
import { BadRequestError } from '../../src/errors/index.js';
import { logger as customLogger } from '../../src/logger.js';

describe('Request ID Propagation', () => {
let app: express.Application;

beforeEach(() => {
jest.clearAllMocks();
jest.restoreAllMocks();

jest.spyOn(pinoLogger, 'info').mockImplementation(() => undefined as any);
jest.spyOn(pinoLogger, 'warn').mockImplementation(() => undefined as any);
jest.spyOn(pinoLogger, 'error').mockImplementation(() => undefined as any);

jest.spyOn(customLogger, 'error').mockImplementation(() => undefined as any);

app = express();
app.use(requestIdMiddleware);
app.use(requestLogger);

app.get('/success', (req, res) => {
res.json({ status: 'ok' });
});

app.get('/error', (req, res, next) => {
next(new BadRequestError('Test bad request'));
});

app.use(errorHandler);
});

afterEach(() => {
jest.restoreAllMocks();
});

it('should propagate a valid generated UUID to the response header and logger for successful requests', async () => {
const response = await request(app).get('/success');

expect(response.status).toBe(200);
const requestId = response.headers['x-request-id'];
expect(requestId).toBeDefined();

const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
expect(requestId).toMatch(uuidRegex);

await new Promise(resolve => setTimeout(resolve, 50));

expect(pinoLogger.info).toHaveBeenCalledWith(
expect.objectContaining({
requestId: requestId,
statusCode: 200,
path: '/success'
}),
'request completed'
);
});

it('should propagate the exact same UUID to error response body and error logger', async () => {
const response = await request(app).get('/error');

expect(response.status).toBe(400);
const headerRequestId = response.headers['x-request-id'];
const bodyRequestId = response.body.requestId;

expect(headerRequestId).toBeDefined();
expect(bodyRequestId).toBeDefined();
expect(headerRequestId).toBe(bodyRequestId);

expect(customLogger.error).toHaveBeenCalledWith(
'[errorHandler]',
expect.objectContaining({
requestId: headerRequestId,
statusCode: 400
})
);

await new Promise(resolve => setTimeout(resolve, 50));

expect(pinoLogger.warn).toHaveBeenCalledWith(
expect.objectContaining({
requestId: headerRequestId,
statusCode: 400,
path: '/error'
}),
'request completed'
);
});

it('should use provided valid UUID and propagate it', async () => {
const validUuid = '123e4567-e89b-12d3-a456-426614174000';
const response = await request(app)
.get('/success')
.set('X-Request-Id', validUuid);

expect(response.status).toBe(200);
expect(response.headers['x-request-id']).toBe(validUuid);

await new Promise(resolve => setTimeout(resolve, 50));

expect(pinoLogger.info).toHaveBeenCalledWith(
expect.objectContaining({
requestId: validUuid
}),
'request completed'
);
});

it('should reject invalid X-Request-Id (e.g. PII) and generate a new UUID', async () => {
const invalidId = 'john.doe@example.com';
const response = await request(app)
.get('/error')
.set('X-Request-Id', invalidId);

expect(response.status).toBe(400);
const headerRequestId = response.headers['x-request-id'];

expect(headerRequestId).toBeDefined();
expect(headerRequestId).not.toBe(invalidId);

const uuidRegex = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i;
expect(headerRequestId).toMatch(uuidRegex);
expect(response.body.requestId).toBe(headerRequestId);

await new Promise(resolve => setTimeout(resolve, 50));

expect(customLogger.error).toHaveBeenCalledWith(
'[errorHandler]',
expect.objectContaining({
requestId: headerRequestId
})
);
});
});
Loading