feat: log unhandled errors and pretty dev output (WealthLedger/backend#120) (#126)
Backend verify / commits (push) Skipped
Backend verify / security (push) Successful in 9s
Backend verify / verify (push) Failing after 5m39s

feat: log unhandled errors and pretty dev output (#120)
This commit was merged in pull request #126.
This commit is contained in:
2026-10-24 15:06:34 +03:00
parent d1f6969dc7
commit 966a1f793a
8 changed files with 251 additions and 48 deletions
+131 -24
View File
@@ -65,6 +65,7 @@
"eslint-plugin-sonarjs": "4.2.1",
"globals": "17.12.0",
"jest": "30.5.1",
"pino-pretty": "13.2.0",
"release-it": "21.0.2",
"supertest": "7.2.2",
"ts-jest": "29.4.12",
@@ -6301,18 +6302,18 @@
}
},
"node_modules/body-parser": {
"version": "2.3.0",
"resolved": "https://registry.npmjs.org/body-parser/-/body-parser-2.3.0.tgz",
"integrity": "sha512-2cGmJupaNgg+QUwVLAucDuWuoMZ6EX9iHDRswZ5lsNYEmwPaRknMPCLZz07yTzVq/83p4o/wzbDZbBrTvGGTIw==",
"version": "2.4.0",
"resolved": "https://registry.npmjs.org/body-parser/-/body-parser-2.4.0.tgz",
"integrity": "sha512-Ifk1KcLrxaGt1occQagQNFNNOqRt1LFuehEnHHzB8Z6cRgIxRU1TBaiIsUiCdA+gy5PL7Y1IX31DNKkRmxtXjQ==",
"license": "MIT",
"dependencies": {
"bytes": "^3.1.2",
"content-type": "^2.0.0",
"content-type": "^2.1.0",
"debug": "^4.4.3",
"http-errors": "^2.0.1",
"iconv-lite": "^0.7.2",
"iconv-lite": "^0.7.3",
"on-finished": "^2.4.1",
"qs": "^6.15.2",
"qs": "^6.16.1",
"raw-body": "^3.0.2",
"type-is": "^2.1.0"
},
@@ -6325,9 +6326,9 @@
}
},
"node_modules/body-parser/node_modules/content-type": {
"version": "2.0.0",
"resolved": "https://registry.npmjs.org/content-type/-/content-type-2.0.0.tgz",
"integrity": "sha512-j/O/d7GcZCyNl7/hwZAb606rzqkyvaDctLmckbxLzHvFBzTJHuGEdodATcP3yIRoDrLHkIATJuvzbFlp/ki2cQ==",
"version": "2.1.0",
"resolved": "https://registry.npmjs.org/content-type/-/content-type-2.1.0.tgz",
"integrity": "sha512-mj7UPXE0jaqaOsukNZRUEfEi2AcL7C/vwmwcHV0O97eO1E1pxBZuyjlZrx5seTaNBg1U6+o35wpa35Qfcc+7ag==",
"license": "MIT",
"engines": {
"node": ">=18"
@@ -6900,6 +6901,13 @@
"integrity": "sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==",
"license": "MIT"
},
"node_modules/colorette": {
"version": "2.0.20",
"resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz",
"integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==",
"dev": true,
"license": "MIT"
},
"node_modules/combined-stream": {
"version": "1.0.8",
"resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz",
@@ -7453,6 +7461,16 @@
"node": ">= 20"
}
},
"node_modules/dateformat": {
"version": "4.6.3",
"resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz",
"integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==",
"dev": true,
"license": "MIT",
"engines": {
"node": "*"
}
},
"node_modules/debug": {
"version": "4.4.3",
"resolved": "https://registry.npmjs.org/debug/-/debug-4.4.3.tgz",
@@ -8868,6 +8886,13 @@
],
"license": "MIT"
},
"node_modules/fast-copy": {
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.2.0.tgz",
"integrity": "sha512-WSlnvPXaMdUjFdgxPkovE4e5aslybVod4TNKrEKKyoA8GoHZzbDLlhDXZOvqjtFgjtOHd9TYCstkUcGXy1+SEA==",
"dev": true,
"license": "MIT"
},
"node_modules/fast-decode-uri-component": {
"version": "1.0.1",
"resolved": "https://registry.npmjs.org/fast-decode-uri-component/-/fast-decode-uri-component-1.0.1.tgz",
@@ -8927,9 +8952,9 @@
}
},
"node_modules/fast-uri": {
"version": "3.1.8",
"resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.8.tgz",
"integrity": "sha512-GZMtZUTNRpOVIECoXwLNZS5xUGE+mVNbTB8h/7Rwh2TFWcBQiPzTgyZi05BF9UMZKkLJv8XBRJTlU7zg8+ZfMg==",
"version": "3.1.9",
"resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.9.tgz",
"integrity": "sha512-hS/0Wt3Ya043oKXs0sIxrMpKQITXhMLIrVAKKXi4gozGC9v7YRWVnXIZzjNPTO02M9BdxLCWqK1yRXgNziVyJQ==",
"funding": [
{
"type": "github",
@@ -9598,6 +9623,13 @@
"node": ">= 0.4"
}
},
"node_modules/help-me": {
"version": "5.0.0",
"resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz",
"integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==",
"dev": true,
"license": "MIT"
},
"node_modules/hookified": {
"version": "1.15.1",
"resolved": "https://registry.npmjs.org/hookified/-/hookified-1.15.1.tgz",
@@ -9818,9 +9850,9 @@
}
},
"node_modules/ip-address": {
"version": "10.7.2",
"resolved": "https://registry.npmjs.org/ip-address/-/ip-address-10.7.2.tgz",
"integrity": "sha512-7H/2gFSIitxc0hG3nOI1glS8QLo/EHBFFLk8vEUjXY/xu0AdL8jZ9U1IzO2PUm0d2D/ofQcAifb0g6OBkt8U7w==",
"version": "10.7.4",
"resolved": "https://registry.npmjs.org/ip-address/-/ip-address-10.7.4.tgz",
"integrity": "sha512-DWBMKyeM25D70nrIiTkgQth59/G+naKOTep6huF9j+GmeK3DMD60Zvxg5d5qQnz+38AHgou6ean2LECX+lrKDg==",
"dev": true,
"license": "MIT",
"engines": {
@@ -10722,6 +10754,16 @@
"jiti": "lib/jiti-cli.mjs"
}
},
"node_modules/joycon": {
"version": "3.1.1",
"resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz",
"integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==",
"dev": true,
"license": "MIT",
"engines": {
"node": ">=10"
}
},
"node_modules/js-tokens": {
"version": "4.0.0",
"resolved": "https://registry.npmjs.org/js-tokens/-/js-tokens-4.0.0.tgz",
@@ -11492,9 +11534,9 @@
"license": "MIT"
},
"node_modules/multer": {
"version": "2.4.0",
"resolved": "https://registry.npmjs.org/multer/-/multer-2.4.0.tgz",
"integrity": "sha512-7dqa0ZcFfzbefdTuIkzOSMvZWC0J7FLqBOjJUZvDCXShIURWKxAyTT1wHhnE5q19c7jOJf43IYYKjBmZVZmvhg==",
"version": "2.5.0",
"resolved": "https://registry.npmjs.org/multer/-/multer-2.5.0.tgz",
"integrity": "sha512-BsqOzYGVq49JcW2IzoSAxeKYRevb+dGGPPWleOR8Lrlk4igwxu1/9pwSXlByhCb7MVZDrNJFC0IBP5/O5nLYRw==",
"license": "MIT",
"dependencies": {
"append-field": "^1.0.0",
@@ -12378,6 +12420,54 @@
"process-warning": "^5.0.0"
}
},
"node_modules/pino-pretty": {
"version": "13.2.0",
"resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.2.0.tgz",
"integrity": "sha512-jjghD1ML+Di/WxjJDz6j6Y4FT7hIXOlb8h27AyJ+ohtAXJXH4PS/xkv7si+RCCIW59HMgZsMKTDgzdr0RhuRrg==",
"dev": true,
"license": "MIT",
"dependencies": {
"colorette": "^2.0.7",
"dateformat": "^4.6.3",
"fast-copy": "^4.0.0",
"fast-safe-stringify": "^2.1.1",
"help-me": "^5.0.0",
"joycon": "^3.1.1",
"minimist": "^1.2.6",
"on-exit-leak-free": "^2.1.2",
"pino-abstract-transport": "^3.0.0",
"pump": "^3.0.3",
"secure-json-parse": "^4.1.0",
"sonic-boom": "^5.0.0",
"strip-json-comments": "^5.0.3"
},
"bin": {
"pino-pretty": "bin.js"
}
},
"node_modules/pino-pretty/node_modules/sonic-boom": {
"version": "5.0.2",
"resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-5.0.2.tgz",
"integrity": "sha512-/JEruzo6yhNVhsLblTRchgTQHIt7SsdJP0YyrfWaNKjIOQDfrdZv9gwYraYCAsmKV39/LAdV31FLL5NCDpoL/A==",
"dev": true,
"license": "MIT",
"dependencies": {
"atomic-sleep": "^1.0.0"
}
},
"node_modules/pino-pretty/node_modules/strip-json-comments": {
"version": "5.0.3",
"resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz",
"integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==",
"dev": true,
"license": "MIT",
"engines": {
"node": ">=14.16"
},
"funding": {
"url": "https://github.com/sponsors/sindresorhus"
}
},
"node_modules/pino-std-serializers": {
"version": "7.1.0",
"resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz",
@@ -12811,9 +12901,9 @@
"license": "MIT"
},
"node_modules/qs": {
"version": "6.16.0",
"resolved": "https://registry.npmjs.org/qs/-/qs-6.16.0.tgz",
"integrity": "sha512-h6fhOIaRrID2CbEY2fqs+7t+UXZo+MLAnU5gRIq85uFtdiUPCdsApMlHhXogKVM4HM2DVbIjGNTTYH2OcmP1vA==",
"version": "6.16.1",
"resolved": "https://registry.npmjs.org/qs/-/qs-6.16.1.tgz",
"integrity": "sha512-5Px6J7rfHBAGUhNQ3es4YzcOdBBw0SDcVtThJml4RdnKw4tKs2epA0kPZ+K8X+WiHktT93RHVcQ/3ym5aTCgtg==",
"license": "BSD-3-Clause",
"dependencies": {
"es-define-property": "^1.0.1",
@@ -13321,6 +13411,23 @@
"node": "^14.0.0 || >=16.0.0"
}
},
"node_modules/secure-json-parse": {
"version": "4.1.1",
"resolved": "https://registry.npmjs.org/secure-json-parse/-/secure-json-parse-4.1.1.tgz",
"integrity": "sha512-lnd81MQEZKjhW/Gd2TQqdd4XP6QYNdDW/EP+I7nTrFHP9y2LmaGPIHk9xsnzcOiEr1c39c/e84xFgGviQKBTRw==",
"dev": true,
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/fastify"
},
{
"type": "opencollective",
"url": "https://opencollective.com/fastify"
}
],
"license": "BSD-3-Clause"
},
"node_modules/semver": {
"version": "7.8.5",
"resolved": "https://registry.npmjs.org/semver/-/semver-7.8.5.tgz",
@@ -14536,9 +14643,9 @@
}
},
"node_modules/undici": {
"version": "7.29.1",
"resolved": "https://registry.npmjs.org/undici/-/undici-7.29.1.tgz",
"integrity": "sha512-RYONW2MeafgYlkVOKYKkA/Ag7BmXqgIWCa8t1m0JcxrQg9pI9lEqRhAOruOBCbAohOa/gkCF+iPi9hrgvTzu6Q==",
"version": "7.30.1",
"resolved": "https://registry.npmjs.org/undici/-/undici-7.30.1.tgz",
"integrity": "sha512-03KrMbjIFDWQR5RNPrSw3bd1r12JpyFQl9/yxjUbJtqkjmllqC5lFjZh6ujeuJCKr8EOQvRW872Oy/az+nLYxg==",
"license": "MIT",
"engines": {
"node": ">=20.18.1"
+12 -2
View File
@@ -95,6 +95,7 @@
"eslint-plugin-sonarjs": "4.2.1",
"globals": "17.12.0",
"jest": "30.5.1",
"pino-pretty": "13.2.0",
"release-it": "21.0.2",
"supertest": "7.2.2",
"ts-jest": "29.4.12",
@@ -106,15 +107,24 @@
},
"overrides": {
"proxy-addr": "2.0.8",
"express": {
"body-parser": "2.4.0"
},
"@nestjs/platform-express": {
"multer": "2.4.0"
"multer": "2.5.0"
},
"ajv": {
"fast-uri": "3.1.9"
},
"@prisma/config@7.10.0": {
"deepmerge-ts": "8.0.2"
},
"release-it": {
"basic-ftp": "6.2.1",
"undici": "7.29.1"
"undici": "7.30.1"
},
"socks": {
"ip-address": "10.7.4"
},
"prisma": {
"mysql2": "3.24.4"
@@ -1,24 +1,29 @@
import { ArgumentsHost } from '@nestjs/common';
import { ArgumentsHost, BadRequestException } from '@nestjs/common';
import { StructuredLogger } from '../logging/structured-logger.service';
import { HttpExceptionFilter } from './http-exception.filter';
describe('HttpExceptionFilter', () => {
it('does not expose internal error details', () => {
const setup = () => {
const status = jest.fn().mockReturnThis();
const type = jest.fn().mockReturnThis();
const json = jest.fn();
const locals: Record<string, unknown> = {};
const filter = new HttpExceptionFilter();
const logger = { event: jest.fn() };
const filter = new HttpExceptionFilter(logger as unknown as StructuredLogger);
const host = {
switchToHttp: () => ({
getResponse: () => ({ status, type, json, locals }),
}),
} as unknown as ArgumentsHost;
return { filter, host, status, type, json, locals, logger };
};
filter.catch(
new Error('operation failed\npassword: SYNTHETIC_AUDIT_SECRET'),
host,
);
it('logs unhandled errors with name and stack frames but never the message', () => {
const { filter, host, status, type, json, locals, logger } = setup();
const error = new Error('operation failed\npassword: SYNTHETIC_AUDIT_SECRET');
filter.catch(error, host);
expect(status).toHaveBeenCalledWith(500);
expect(type).toHaveBeenCalledWith('application/problem+json');
@@ -27,6 +32,29 @@ describe('HttpExceptionFilter', () => {
code: 'INTERNAL_SERVER_ERROR',
});
expect(locals.publicErrorCode).toBe('INTERNAL_SERVER_ERROR');
expect(locals.errorStack).toBeUndefined();
expect(logger.event).toHaveBeenCalledTimes(1);
const [level, event, fields] = logger.event.mock.calls[0] as [string, string, Record<string, unknown>];
expect(level).toBe('error');
expect(event).toBe('http.request.unhandled');
expect(fields).toMatchObject({ code: 'INTERNAL_SERVER_ERROR', errorName: 'Error' });
expect(JSON.stringify(fields)).not.toContain('SYNTHETIC_AUDIT_SECRET');
expect(String(fields['errorStack']).split('\n').every((line) => line.startsWith(' at '))).toBe(true);
});
it('logs field pointers without values for validation errors', () => {
const { filter, host, status, logger, locals } = setup();
const exception = new BadRequestException({
message: [
{ property: 'amount', constraints: { isPositive: 'amount must be positive' }, value: -42 },
{ property: 'amount', constraints: { min: 'amount too small' }, value: -42 },
],
});
filter.catch(exception, host);
expect(status).toHaveBeenCalledWith(400);
expect(locals.invalidFields).toBe('#/amount');
expect(logger.event).not.toHaveBeenCalled();
expect(JSON.stringify(locals)).not.toContain('-42');
});
});
@@ -10,9 +10,12 @@ import {
} from '@nestjs/common';
import { HttpErrorCode } from '../error-code';
import { StructuredLogger } from '../logging/structured-logger.service';
@Catch()
export class HttpExceptionFilter implements ExceptionFilter {
constructor(private readonly logger: StructuredLogger) {}
catch(exception: unknown, host: ArgumentsHost): void {
const context = host.switchToHttp();
const response = context.getResponse<Response>();
@@ -31,6 +34,18 @@ export class HttpExceptionFilter implements ExceptionFilter {
: this.codeFor(status, payload);
response.locals ??= {};
response.locals.publicErrorCode = code;
if (isValidation) {
response.locals.invalidFields = [
...new Set(
this.validationErrors(
(payload as { message: ValidationError[] }).message,
).map((error) => error.pointer),
),
].join(',');
}
if (!(exception instanceof HttpException)) {
this.logUnhandled(exception, code);
}
response
.status(status)
.type('application/problem+json')
@@ -47,6 +62,20 @@ export class HttpExceptionFilter implements ExceptionFilter {
});
}
// ponytail: stack содержит текст message в первой строке; оставляем только кадры, message не пишем.
private logUnhandled(exception: unknown, code: string): void {
const error = exception instanceof Error ? exception : undefined;
const frames = (error?.stack ?? '')
.split('\n')
.filter((line) => line.startsWith(' at '))
.join('\n');
this.logger.event('error', 'http.request.unhandled', {
code,
errorName: error?.name ?? typeof exception,
errorStack: frames,
});
}
private codeFor(status: number, payload: unknown): string {
if (typeof payload === 'object' && payload !== null && 'code' in payload) {
const code = (payload as { code?: unknown }).code;
+5
View File
@@ -24,6 +24,7 @@ function completion(request: Request, response: Response, value: { responseTime:
status: response.statusCode,
durationMs: Math.round(value.responseTime),
...(typeof response.locals.publicErrorCode === 'string' ? { code: response.locals.publicErrorCode } : {}),
...(typeof response.locals.invalidFields === 'string' ? { invalidFields: response.locals.invalidFields } : {}),
};
}
@@ -31,6 +32,10 @@ export function loggingOptions(config: ConfigService<Environment, true>): Option
return {
level: config.getOrThrow('LOG_LEVEL'),
messageKey: 'message',
// ponytail: development-only pretty output; production never loads pino-pretty.
...(process.env['NODE_ENV'] === 'development'
? { transport: { target: 'pino-pretty', options: { colorize: true, singleLine: true, messageKey: 'message' } } }
: {}),
genReqId: (_request, response) => {
const id = randomUUID();
response.setHeader('X-Request-ID', id);
@@ -14,9 +14,12 @@ const allowedFields = new Set([
'count',
'durationMs',
'environment',
'errorName',
'errorStack',
'found',
'grpcCode',
'headersReceived',
'invalidFields',
'method',
'networkMs',
'operation',
+1 -1
View File
@@ -37,7 +37,7 @@ export function configureApp(app: INestApplication): void {
exceptionFactory: (message) => new BadRequestException({ message }),
}),
);
app.useGlobalFilters(new HttpExceptionFilter());
app.useGlobalFilters(new HttpExceptionFilter(app.get(StructuredLogger)));
app.enableShutdownHooks();
}
+34 -13
View File
@@ -32,6 +32,7 @@ describe('Authentication (e2e)', () => {
pinoHttp: {
...loggingOptions(config),
level: 'info',
transport: undefined,
stream: { write: (line: string) => logs.push(JSON.parse(line) as Record<string, unknown>) },
},
assignResponse: true,
@@ -539,7 +540,14 @@ describe('Authentication (e2e)', () => {
'X-Request-ID',
);
expect(logs.filter((entry) => entry.requestId === response.headers['x-request-id'])).toEqual([
expect.objectContaining({ level: 40, message: 'http.request.completed', status: 401, code: 'UNAUTHORIZED' }),
expect.objectContaining({
level: 40,
message: 'http.request.completed',
method: 'GET',
route: '/api/v1/auth/me',
status: 401,
code: 'UNAUTHORIZED',
}),
]);
});
@@ -551,7 +559,7 @@ describe('Authentication (e2e)', () => {
new Error('operation failed\npassword: SYNTHETIC_AUDIT_SECRET'),
);
const response = await request(app.getHttpServer())
await request(app.getHttpServer())
.post('/api/v1/auth/login')
.set('X-Request-ID', clientRequestId)
.send({ email: 'user@example.com', password: 'a secure password' })
@@ -561,17 +569,30 @@ describe('Authentication (e2e)', () => {
expect(body).toEqual({ status: 500, code: 'INTERNAL_SERVER_ERROR' }),
);
const completed = logs.filter((entry) => entry.requestId === response.headers['x-request-id']);
expect(completed).toEqual([
expect.objectContaining({
requestId: response.headers['x-request-id'],
clientRequestId,
status: 500,
code: 'INTERNAL_SERVER_ERROR',
level: 50,
message: 'http.request.completed',
}),
]);
expect(logs).toEqual(
expect.arrayContaining([
expect.objectContaining({
method: 'POST',
route: '/api/v1/auth/login',
status: 500,
code: 'INTERNAL_SERVER_ERROR',
level: 50,
message: 'http.request.completed',
}),
]),
);
expect(logs).toEqual(
expect.arrayContaining([
expect.objectContaining({
clientRequestId,
code: 'INTERNAL_SERVER_ERROR',
level: 50,
message: 'http.request.unhandled',
errorName: 'Error',
errorStack: expect.stringContaining(' at ') as unknown,
}),
]),
);
expect(JSON.stringify(logs)).not.toContain(
'SYNTHETIC_AUDIT_SECRET',
);