feat: log unhandled errors and pretty dev output (WealthLedger/backend#120)

package-lock.json

@@ -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",
@@ -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",
@@ -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",
@@ -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",
@@ -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",
@@ -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",

package.json

@@ -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",

src/common/filters/http-exception.filter.spec.ts

@@ -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(
+  it('logs unhandled errors with name and stack frames but never the message', () => {
-      new Error('operation failed\npassword: SYNTHETIC_AUDIT_SECRET'),
+    const { filter, host, status, type, json, locals, logger } = setup();
-      host,
+    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');
   });
 });

src/common/filters/http-exception.filter.ts

@@ -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;

src/common/logging/logging.module.ts

@@ -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);

src/common/logging/structured-logger.service.ts

@@ -14,9 +14,12 @@ const allowedFields = new Set([
   'count',
   'durationMs',
   'environment',
+  'errorName',
+  'errorStack',
   'found',
   'grpcCode',
   'headersReceived',
+  'invalidFields',
   'method',
   'networkMs',
   'operation',

src/main.ts

@@ -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();
 }
 

test/app.e2e-spec.ts

@@ -554,8 +554,17 @@ describe('Authentication (e2e)', () => {
         expect(body).toEqual({ status: 500, code: 'INTERNAL_SERVER_ERROR' }),
       );
 
-    const completed = logs.filter((entry) => entry.requestId === response.headers['x-request-id']);
+    const related = logs.filter((entry) => entry.requestId === response.headers['x-request-id']);
-    expect(completed).toEqual([
+    expect(related).toEqual([
+      expect.objectContaining({
+        requestId: response.headers['x-request-id'],
+        clientRequestId,
+        code: 'INTERNAL_SERVER_ERROR',
+        level: 50,
+        message: 'http.request.unhandled',
+        errorName: 'Error',
+        errorStack: expect.stringContaining('    at ') as unknown,
+      }),
       expect.objectContaining({
         requestId: response.headers['x-request-id'],
         clientRequestId,