Custom decorator cuts off part of error stack | NestJS | Page 1

dull plume Dec 18, 2024, 3:17 AM

I have a custom decorator to save the result of method execution to in-memory cache, but when decorated method throws and exception, the original error stack is lost.

Here's my decorator

/* eslint-disable @typescript-eslint/no-explicit-any */
import { Cache } from 'cache-manager';

import { CACHE_MANAGER } from '@nestjs/cache-manager';
import { Inject } from '@nestjs/common';

interface InMemoryCacheOptions {
  key: (...args: any[]) => string;
  ttl: number;
}

export function InMemoryCache(
  options: InMemoryCacheOptions,
): (target: unknown, propertyKey: string, descriptor: PropertyDescriptor) => PropertyDescriptor {
  const injectCacheManagerService = Inject(CACHE_MANAGER);

  return (target: any, propertyKey: string, descriptor: PropertyDescriptor) => {
    const originalMethod = descriptor.value;

    injectCacheManagerService(target, 'InMemoryCacheCacheManager');

    // eslint-disable-next-line no-param-reassign, func-names
    descriptor.value = async function (...args: unknown[]): Promise<unknown> {
      const cacheKey = options.key(...args);
      // InMemoryCacheCacheManager is injected by Inject(CACHE_MANAGER)
      // eslint-disable-next-line @typescript-eslint/ban-ts-comment
      // @ts-expect-error
      const cacheManager = this.InMemoryCacheCacheManager as Cache;
      const cachedData = await cacheManager.get<string>(cacheKey);

      if (cachedData) {
        return JSON.parse(cachedData);
      }

      const result = await originalMethod.apply(this, args);

      await cacheManager.set(cacheKey, JSON.stringify(result), options.ttl);

      return result;
    };

    return descriptor;
  };
}

Here's how exception looks normally:

[flaut-nestjs] Error    12/18/2024, 5:11:29 AM [ExceptionsHandler] This is a test exception - {
  service: 'flaut-nestjs',
  stack: [
    'Error: This is a test exception\n' +
      '    at ExceptionsTestService.triggerUncached (/home/goodwin/flaut/flaut-nestjs/src/exceptions-test/exceptions-test.service.ts:16:11)\n' +
      '    at ExceptionsTestController.triggerUncached (/home/goodwin/flaut/flaut-nestjs/src/exceptions-test/exceptions-test.controller.ts:16:25)\n' +
      '    at /home/goodwin/flaut/flaut-nestjs/node_modules/@nestjs/core/router/router-execution-context.js:38:29\n' +
      '    at InterceptorsConsumer.transformDeferred (/home/goodwin/flaut/flaut-nestjs/node_modules/@nestjs/core/interceptors/interceptors-consumer.js:31:33)\n' +
      '    at /home/goodwin/flaut/flaut-nestjs/node_modules/@nestjs/core/interceptors/interceptors-consumer.js:18:86\n' +
      '    at AsyncResource.runInAsyncScope (node:async_hooks:206:9)\n' +
      '    at bound (node:async_hooks:238:16)\n' +
      '    at Observable._subscribe (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/observable/defer.ts:55:15)\n' +
      '    at Observable.Observable._trySubscribe (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/Observable.ts:244:19)\n' +
      '    at <anonymous> (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/Observable.ts:234:18)\n' +
      '    at Object.errorContext (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/util/errorContext.ts:29:5)\n' +
      '    at Observable.Observable.subscribe (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/Observable.ts:220:5)\n' +
      '    at doInnerSub (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/operators/mergeInternals.ts:71:40)\n' +
      '    at outerNext (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/operators/mergeInternals.ts:53:58)\n' +
      '    at OperatorSubscriber.OperatorSubscriber._this._next (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/operators/OperatorSubscriber.ts:70:13)\n' +
      '    at OperatorSubscriber.Subscriber.next (/home/goodwin/flaut/flaut-nestjs/node_modules/rxjs/src/internal/Subscriber.ts:75:12)'
  ]
}

And here's how it looks when decorated:

[flaut-nestjs] Error    12/18/2024, 4:58:51 AM [ExceptionsHandler] This is a test exception - {
  service: 'flaut-nestjs',
  stack: [
    'Error: This is a test exception\n' +
      '    at ExceptionsTestService.trigger (/home/goodwin/flaut/flaut-nestjs/src/exceptions-test/exceptions-test.service.ts:12:11)\n' +
      '    at ExceptionsTestService.descriptor.value (/home/goodwin/flaut/flaut-nestjs/src/shared/decorators/in-memory-cache.decorator.ts:35:43)\n' +
      '    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)'
  ]
}

Is my custom decorator interferes with NestJS somehow? Not sure what I'm doing wrong here. I just want to preserve the original error stack and let Sentry capture the error.

dull plume Dec 19, 2024, 7:38 PM

Sorry for pinging you directly @ebon bramble

Maybe you could give me at least a hint on where I should look? I've seen that other developers are making their own separate modules and providers, and using applyDecorators from @nestjs/common. Though I'm not sure if that's applicable to injectable class methods. Thank you in advance.

ebon bramble Dec 19, 2024, 8:05 PM

So, the error is changing when you use @InMemoryCache() on a method in your service?

dull plume Dec 19, 2024, 9:26 PM

To put it simply, yes. The stack is drastically shorter and in production I cannot track the endpoint that caused it, and the error is not being reported to Sentry. I think that's because it never reaches the top interceptor.

ebon bramble Dec 19, 2024, 9:43 PM

I believe this is generally due to the fact that the dedscriptor.value is being modified, even though you're calling the original under the hood, so it changes what the stack trace ends up looking like. I think this is a typescrip thing, not necessarily a Nest thing

#Custom decorator cuts off part of error stack