Skip to content

Commit 149bb9f

Browse files
committed
feat: structured body-parse error log and client-IP extraction helper
Issue #288 — src/middlewares/body-parse-error.middleware.ts - New error-handler middleware that intercepts body-parsing failures (SyntaxError with body, entity.too.large) exclusively on mutation methods (POST, PUT, PATCH, DELETE) - Emits logger.error with: type, method, path, requestId, clientIp, errorType — never logs the raw body or request headers - Returns 400 / 413 JSON to the client unchanged; non-parse errors and GET/HEAD/OPTIONS pass straight through to next() - Mounted in app.ts immediately after express.json() so parse errors are caught before any route or the global error handler sees them - 14 tests covering: all mutation verbs, GET passthrough, generic errors, entity.too.large, no-body-in-log assertion, client response shape Issue #289 — src/utils/client-ip.utils.ts - getClientIp(req, trusted?) reads the first IP from X-Forwarded-For when the socket address belongs to a trusted proxy (loopback, RFC-1918, IPv6 ULA); falls back to req.socket.remoteAddress otherwise - Accepts an optional predicate override for testing and custom deployments - Integrated into request-logger.middleware.ts (clientIp field in every request log entry) and body-parse-error.middleware.ts (clientIp in parse-failure logs) - 11 tests: trusted loopback/private ranges, array header, custom predicate, untrusted socket passthrough, missing socket edge cases Closes #288 Closes #289
1 parent a7d197e commit 149bb9f

6 files changed

Lines changed: 400 additions & 0 deletions

File tree

src/app.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@ import { apiVersionMiddleware } from './middlewares/api-version.middleware';
1515
import { schemaVersionMiddleware } from './middlewares/schema-version.middleware';
1616
import { requestLoggerMiddleware } from './middlewares/request-logger.middleware';
1717
import { requestContextMiddleware } from './middlewares/request-context.middleware';
18+
import { bodyParseErrorMiddleware } from './middlewares/body-parse-error.middleware';
1819
import { envConfig } from './config';
1920

2021
const app: Express = express();
@@ -29,6 +30,7 @@ app.use(requestIdMiddleware);
2930
app.use(corsMiddleware());
3031
app.use(helmet());
3132
app.use(express.json({ limit: '10mb' }));
33+
app.use(bodyParseErrorMiddleware);
3234

3335
if (!envConfig.ENABLE_REQUEST_LOGGING) {
3436
app.use(morgan('combined'));
Lines changed: 169 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,169 @@
1+
import { Request, Response, NextFunction } from 'express';
2+
import { bodyParseErrorMiddleware } from './body-parse-error.middleware';
3+
import { logger } from '../utils/logger.utils';
4+
5+
jest.mock('../utils/logger.utils', () => ({
6+
logger: { error: jest.fn() },
7+
}));
8+
9+
jest.mock('../utils/client-ip.utils', () => ({
10+
getClientIp: jest.fn(() => '10.0.0.1'),
11+
}));
12+
13+
function makeReq(method: string, url = '/api/v1/resource'): Request {
14+
return {
15+
method,
16+
originalUrl: url,
17+
url,
18+
requestId: 'req-test-id',
19+
socket: { remoteAddress: '127.0.0.1' },
20+
headers: {},
21+
} as unknown as Request;
22+
}
23+
24+
function makeRes(): Partial<Response> {
25+
const res: Partial<Response> = {};
26+
res.status = jest.fn().mockReturnValue(res);
27+
res.json = jest.fn().mockReturnValue(res);
28+
return res;
29+
}
30+
31+
function makeSyntaxError(): SyntaxError & { body: string } {
32+
const err = new SyntaxError('Unexpected token } in JSON') as SyntaxError & { body: string };
33+
err.body = 'raw body';
34+
return err;
35+
}
36+
37+
function makeEntityTooLargeError() {
38+
return Object.assign(new Error('request entity too large'), {
39+
type: 'entity.too.large',
40+
status: 413,
41+
limit: 10 * 1024 * 1024,
42+
});
43+
}
44+
45+
describe('bodyParseErrorMiddleware', () => {
46+
let next: jest.Mock;
47+
48+
beforeEach(() => {
49+
next = jest.fn();
50+
jest.clearAllMocks();
51+
});
52+
53+
describe('malformed JSON on mutation methods', () => {
54+
const MUTATION_METHODS = ['POST', 'PUT', 'PATCH', 'DELETE'];
55+
56+
it.each(MUTATION_METHODS)(
57+
'logs error and returns 400 for %s with invalid JSON',
58+
(method) => {
59+
const err = makeSyntaxError();
60+
const req = makeReq(method);
61+
const res = makeRes();
62+
63+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
64+
65+
expect(logger.error).toHaveBeenCalledWith(
66+
expect.objectContaining({
67+
type: 'body_parse_failure',
68+
method,
69+
path: '/api/v1/resource',
70+
requestId: 'req-test-id',
71+
errorType: 'invalid_json',
72+
})
73+
);
74+
expect(res.status).toHaveBeenCalledWith(400);
75+
expect(res.json).toHaveBeenCalledWith(
76+
expect.objectContaining({ success: false, message: 'Invalid JSON in request body' })
77+
);
78+
expect(next).not.toHaveBeenCalled();
79+
}
80+
);
81+
82+
it('does not include raw body in the log', () => {
83+
const err = makeSyntaxError();
84+
const req = makeReq('POST');
85+
const res = makeRes();
86+
87+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
88+
89+
const logCall = (logger.error as jest.Mock).mock.calls[0][0];
90+
expect(logCall).not.toHaveProperty('body');
91+
expect(logCall).not.toHaveProperty('rawBody');
92+
});
93+
94+
it('logs and returns 413 for entity.too.large on mutation', () => {
95+
const err = makeEntityTooLargeError();
96+
const req = makeReq('POST');
97+
const res = makeRes();
98+
99+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
100+
101+
expect(logger.error).toHaveBeenCalledWith(
102+
expect.objectContaining({ errorType: 'entity.too.large' })
103+
);
104+
expect(res.status).toHaveBeenCalledWith(413);
105+
});
106+
});
107+
108+
describe('non-mutation methods', () => {
109+
it('calls next() for GET with a SyntaxError (not a mutation)', () => {
110+
const err = makeSyntaxError();
111+
const req = makeReq('GET');
112+
const res = makeRes();
113+
114+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
115+
116+
expect(next).toHaveBeenCalledWith(err);
117+
expect(logger.error).not.toHaveBeenCalled();
118+
});
119+
120+
it('calls next() for HEAD with a SyntaxError', () => {
121+
const err = makeSyntaxError();
122+
const req = makeReq('HEAD');
123+
const res = makeRes();
124+
125+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
126+
127+
expect(next).toHaveBeenCalledWith(err);
128+
});
129+
});
130+
131+
describe('non-parse errors', () => {
132+
it('calls next() for a generic Error on a mutation method', () => {
133+
const err = new Error('Something else entirely');
134+
const req = makeReq('POST');
135+
const res = makeRes();
136+
137+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
138+
139+
expect(next).toHaveBeenCalledWith(err);
140+
expect(logger.error).not.toHaveBeenCalled();
141+
});
142+
143+
it('calls next() for an ApiError on a mutation method', () => {
144+
const err = Object.assign(new Error('Not found'), { statusCode: 404 });
145+
const req = makeReq('PUT');
146+
const res = makeRes();
147+
148+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
149+
150+
expect(next).toHaveBeenCalledWith(err);
151+
});
152+
});
153+
154+
describe('client response behaviour unchanged', () => {
155+
it('returns 400 JSON with success:false and does not call next', () => {
156+
const err = makeSyntaxError();
157+
const req = makeReq('POST');
158+
const res = makeRes();
159+
160+
bodyParseErrorMiddleware(err, req, res as Response, next as NextFunction);
161+
162+
expect(res.status).toHaveBeenCalledWith(400);
163+
expect((res.json as jest.Mock).mock.calls[0][0]).toMatchObject({
164+
success: false,
165+
});
166+
expect(next).not.toHaveBeenCalled();
167+
});
168+
});
169+
});
Lines changed: 68 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,68 @@
1+
import { Request, Response, NextFunction } from 'express';
2+
import { logger } from '../utils/logger.utils';
3+
import { getClientIp } from '../utils/client-ip.utils';
4+
import { ErrorCode } from '../constants/error.constants';
5+
6+
const MUTATION_METHODS = new Set(['POST', 'PUT', 'PATCH', 'DELETE']);
7+
8+
/**
9+
* Intercepts body-parsing errors on mutation endpoints (POST, PUT, PATCH,
10+
* DELETE) and emits a structured error-level log entry before returning the
11+
* client a 400 response.
12+
*
13+
* What IS logged:
14+
* - endpoint path
15+
* - HTTP method
16+
* - request ID (for correlation)
17+
* - client IP (extracted via the trusted-proxy-aware helper)
18+
* - error type / code
19+
*
20+
* What is NOT logged:
21+
* - raw request body (never read or forwarded)
22+
* - request headers beyond what Express already exposes on req
23+
*/
24+
export const bodyParseErrorMiddleware = (
25+
err: any,
26+
req: Request,
27+
res: Response,
28+
next: NextFunction
29+
): void => {
30+
const isSyntaxError =
31+
err instanceof SyntaxError && 'body' in err;
32+
const isEntityTooLarge =
33+
err.type === 'entity.too.large' ||
34+
err.status === 413 ||
35+
err.statusCode === 413;
36+
37+
const isParseFailure = isSyntaxError || isEntityTooLarge;
38+
39+
if (!isParseFailure || !MUTATION_METHODS.has(req.method)) {
40+
return next(err);
41+
}
42+
43+
const clientIp = getClientIp(req);
44+
45+
logger.error({
46+
type: 'body_parse_failure',
47+
method: req.method,
48+
path: req.originalUrl || req.url,
49+
requestId: req.requestId,
50+
clientIp,
51+
errorType: isEntityTooLarge ? 'entity.too.large' : 'invalid_json',
52+
});
53+
54+
if (isEntityTooLarge) {
55+
res.status(413).json({
56+
success: false,
57+
code: ErrorCode.BAD_REQUEST,
58+
message: 'Request payload too large',
59+
});
60+
return;
61+
}
62+
63+
res.status(400).json({
64+
success: false,
65+
code: ErrorCode.BAD_REQUEST,
66+
message: 'Invalid JSON in request body',
67+
});
68+
};

src/middlewares/request-logger.middleware.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ import { Request, Response, NextFunction } from 'express';
33
import { envConfig } from '../config';
44
import { logger } from '../utils/logger.utils';
55
import { computeRequestContextHash } from '../utils/request-context-hash.utils';
6+
import { getClientIp } from '../utils/client-ip.utils';
67

78
/**
89
* Lightweight request logging middleware.
@@ -39,6 +40,7 @@ export const requestLoggerMiddleware = (
3940
status: res.statusCode,
4041
duration: `${durationMs}ms`,
4142
requestId: req.requestId,
43+
clientIp: getClientIp(req),
4244
contextHash,
4345
});
4446
});

src/utils/client-ip.utils.test.ts

Lines changed: 96 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,96 @@
1+
import { getClientIp } from './client-ip.utils';
2+
import { Request } from 'express';
3+
4+
function makeReq(
5+
socketIp: string,
6+
forwardedFor?: string
7+
): Request {
8+
return {
9+
socket: { remoteAddress: socketIp },
10+
headers: forwardedFor ? { 'x-forwarded-for': forwardedFor } : {},
11+
} as unknown as Request;
12+
}
13+
14+
describe('getClientIp', () => {
15+
describe('when socket is a trusted proxy', () => {
16+
it('returns the first X-Forwarded-For IP', () => {
17+
const req = makeReq('127.0.0.1', '203.0.113.5, 10.0.0.1');
18+
expect(getClientIp(req)).toBe('203.0.113.5');
19+
});
20+
21+
it('handles a single IP in X-Forwarded-For', () => {
22+
const req = makeReq('10.0.0.2', '198.51.100.7');
23+
expect(getClientIp(req)).toBe('198.51.100.7');
24+
});
25+
26+
it('trims whitespace from the extracted IP', () => {
27+
const req = makeReq('192.168.1.1', ' 1.2.3.4 , 10.0.0.5');
28+
expect(getClientIp(req)).toBe('1.2.3.4');
29+
});
30+
31+
it('falls back to socket address when X-Forwarded-For is absent', () => {
32+
const req = makeReq('10.10.10.1');
33+
expect(getClientIp(req)).toBe('10.10.10.1');
34+
});
35+
36+
it('falls back to socket address when X-Forwarded-For is empty string', () => {
37+
const req = makeReq('172.16.0.1', '');
38+
expect(getClientIp(req)).toBe('172.16.0.1');
39+
});
40+
41+
it('handles array-valued X-Forwarded-For header', () => {
42+
const req = {
43+
socket: { remoteAddress: '127.0.0.1' },
44+
headers: { 'x-forwarded-for': ['9.9.9.9, 10.0.0.1', '8.8.8.8'] },
45+
} as unknown as Request;
46+
expect(getClientIp(req)).toBe('9.9.9.9');
47+
});
48+
49+
it('accepts private 172.16.x.x as a trusted proxy', () => {
50+
const req = makeReq('172.16.5.10', '55.55.55.55');
51+
expect(getClientIp(req)).toBe('55.55.55.55');
52+
});
53+
54+
it('accepts IPv6 loopback ::1 as trusted proxy', () => {
55+
const req = makeReq('::1', '203.0.113.99');
56+
expect(getClientIp(req)).toBe('203.0.113.99');
57+
});
58+
});
59+
60+
describe('when socket is NOT a trusted proxy', () => {
61+
it('ignores X-Forwarded-For and returns the socket address', () => {
62+
const req = makeReq('203.0.113.1', '1.2.3.4');
63+
expect(getClientIp(req)).toBe('203.0.113.1');
64+
});
65+
66+
it('returns socket address even when no forwarded header is present', () => {
67+
const req = makeReq('8.8.8.8');
68+
expect(getClientIp(req)).toBe('8.8.8.8');
69+
});
70+
});
71+
72+
describe('custom trusted predicate', () => {
73+
it('uses the override predicate instead of the default CIDR check', () => {
74+
const req = makeReq('8.8.8.8', '203.0.113.42');
75+
// Treat all IPs as trusted via override
76+
expect(getClientIp(req, () => true)).toBe('203.0.113.42');
77+
});
78+
79+
it('rejects all proxies when override always returns false', () => {
80+
const req = makeReq('127.0.0.1', '203.0.113.42');
81+
expect(getClientIp(req, () => false)).toBe('127.0.0.1');
82+
});
83+
});
84+
85+
describe('edge cases', () => {
86+
it('returns undefined when socket address is missing', () => {
87+
const req = { socket: {}, headers: {} } as unknown as Request;
88+
expect(getClientIp(req)).toBeUndefined();
89+
});
90+
91+
it('returns undefined when socket itself is undefined', () => {
92+
const req = { headers: {} } as unknown as Request;
93+
expect(getClientIp(req)).toBeUndefined();
94+
});
95+
});
96+
});

0 commit comments

Comments
 (0)