getsentry / sentry-javascript

Official Sentry SDKs for JavaScript
https://sentry.io
MIT License
8.01k stars 1.58k forks source link

NestJS TypeScript sentry issues not showing local variables for errors #13768

Closed ganjianwei closed 2 weeks ago

ganjianwei commented 1 month ago

Is there an existing issue for this?

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/nestjs

SDK Version

8.30.0

Framework Version

NestJS 10.3.0

Link to Sentry event

https://bloom-studios.sentry.io/issues/5891977466/?project=4506396368568320

Reproduction Example/SDK Setup

import { GrpcInstrumentation } from '@opentelemetry/instrumentation-grpc';
import * as Sentry from '@sentry/nestjs';
import { nodeProfilingIntegration } from '@sentry/profiling-node';

const IGNORE_TRANSACTIONS = [
  /__ApolloGetServiceDefinition__/g,
  /graphql.parse/g,
  /graphql.parseSchema/g,
  /redis-connect/g,
];

const MIN_TRANSACTION_DURATION = 0.3;

export function sentryInit() {
  // Ensure to call this before requiring any other modules!
  Sentry.init({
    dsn: process.env.SENTRY_DSN,
    attachStacktrace: true,
    environment: process.env.ENV,
    enabled: Boolean(process.env.IS_CLOUD),
    includeLocalVariables: true,
    integrations: [
      // Add our Profiling integration
      nodeProfilingIntegration(),
      Sentry.extraErrorDataIntegration({ captureErrorCause: true, depth: 10 }),
      Sentry.graphqlIntegration(),
      Sentry.dedupeIntegration(),
      Sentry.localVariablesIntegration({ captureAllExceptions: true }),
    ],
    ignoreTransactions: IGNORE_TRANSACTIONS,
    tracesSampleRate: 1.0,
    profilesSampleRate: 1.0,
    beforeSendTransaction(event) {
      if (event.timestamp && event.start_timestamp) {
        const duration = event.timestamp - event.start_timestamp;

        if (duration >= MIN_TRANSACTION_DURATION) {
          if (event.transaction?.includes('graphql')) {
            const match = /POST \/graphql \((.+)\)/.exec(event.transaction);
            const parsedOperation = match?.[1];

            if (parsedOperation) {
              event.transaction = parsedOperation.replace(/__.*/g, '');
            }
          }

          return event;
        }
      }

      return null;
    },
  });

  Sentry.addOpenTelemetryInstrumentation(new GrpcInstrumentation());
}

export const SentryGraphqlHooks = {
  preExecution: (_schema, documentNode, _mercuriusContext, variables) => {
    const operationDefinition = documentNode.definitions.find(
      (def) => def.kind === 'OperationDefinition'
    );
    const operation = operationDefinition?.operation;
    const operationName = operationDefinition?.name?.value?.replace(
      /__.*/g,
      ''
    );
    const currentScope = Sentry.getCurrentScope();

    if (operation) {
      currentScope.setTag(operation, operationName);
      currentScope.setTransactionName(`${operation} ${operationName}`);
      currentScope.setContext('variables', variables);
    }
  },
};

Steps to Reproduce

Setup NestJS (TypeScript) server app with Sentry like our above setup with:

    includeLocalVariables: true,
    integrations: [
      // ...
      Sentry.localVariablesIntegration({ captureAllExceptions: true }),
    ],

We also use GraphQL with Mercurius & Fastify.

Have any NestJS module > service > any other code throw an error, and it does not show local variables.

Note we used to use "@sentry/node": "^7.110.1" and just tried changing to NestJS to fix this issue, but to no avail.

Expected Result

I'd expect to see local variables in my Sentry page for easier debugging, as we've seen in other integrations (e.g. Django/Python, and also we see the local variables when there's errors in our NestJS controller code specifically, but not everywhere else).

E.g. from your blog post: https://blog.sentry.io/local-variables-for-nodejs-in-sentry/

Image

Actual Result

No local variables in my Sentry issue page for debugging

E.g. Image Image Image

Thank you!

Lms24 commented 1 month ago

Hi @ganjianwei thanks for writing in! Local variables in Node/JS are a bit more complicated than in other languages like python. But I'm gonna tag our local variables integration expert: @timfish could you take a look when you have some time? Thanks!

timfish commented 1 month ago

v8.30.0 of the SDKs saw some major changes and improvements to local variables capture but this only affects Node >= v20.

@ganjianwei What version of Node are you using?

ganjianwei commented 1 month ago

hey @timfish we're using Node v20.10.0.

in case it's helpful, we remember some Sentry issues where it showed local instance variables (e.g. in the NestJS controller code?) so we thought it was because of Mercurius. Unfortunately I can't find those issues with local vars captured to easily pull up

Then for this example below it's being run in a bull queue so maybe bull's exception handling for the bull dashboard is messing with Sentry capturing the local vars? Image

Thank you! 🙏

Lms24 commented 1 month ago

@ganjianwei any chance you could provide a minimal reproducible example for this?

timfish commented 1 month ago

Local variables are fetched through the debugging interface but if we can't apply them to the stack trace they will be missing. We've seen instances where they can't be applied because the stack frames from error.stack and the debugger don't match. There's already an open issue for this related to additional async frames so it might be related.

designblooz commented 1 month ago

So far here's what I found.

The worker that is responsible for capturing local vars from node inspector crashes sometimes on error or when the app starts initially.

https://github.com/getsentry/sentry-javascript/blob/develop/packages/node/src/integrations/local-variables/worker.ts#L158 This is where the error occurs due to the objectId being passed no longer exists.

Image

So I manually modified the node_modules/@sentry/node/build/cjs/integrations/local-variables/local-variables-async.js to use my custom worker script in base64 that includes try/catch for the code that is causing the worker to terminate.

The worker lives, and gets the local vars, but fails to assign the correct localVariables to the exception object.

Image

The __SENTRY_ERROR_LOCAL_VARIABLES__ looked like rxjs related objects so tried removing the SentryModule.forRoot() in app.module since it contains interceptor that requires it to return an Observable.

After removing it, correct local vars was being assigned to the exception object.

Image

Critical bug

Issue

I created sample Nestjs App with Fastify + Mercurius that you can use to debug that reproduces this issue. https://github.com/designblooz/nestjs-sentry-bug

timfish commented 1 month ago

@designblooz thanks for taking the time to debug this. I've opened a PR to add the try/catch.

I need to look further into the interceptor issue.

Bruno-DaSilva commented 1 month ago

xref this comment I added to the PR of why I think this happens: https://github.com/getsentry/sentry-javascript/pull/13827#issuecomment-2381337006

a minimal reproducible example would likely be to throw an exception but immediately throw it away (+ let it be GC'd?) without doing a Sentry.captureException(). Perhaps that could be added as a test.

I believe what's happening is exceptions that get caught and thrown away before the 1s releaseObject timer runs result in this lovely inspector error Image

ganjianwei commented 1 month ago

hey sentry folks, let us know if you have a timeline / if it's fixable, especially the interceptor issue. Or if there's any workarounds we should try on our side. thanks again for looking into this!

chargome commented 1 month ago

@ganjianwei you can watch https://github.com/getsentry/sentry-javascript/pull/13827

AbhiPrasad commented 2 weeks ago

We've merged and released https://github.com/getsentry/sentry-javascript/pull/13827 + have expanded our docs to indicate places where local variables might not work as expected (usually when using esm setups).

Please upgrade your SDK to the latest version and try again.

Going to close this for now as such. Please re-open if this is still a problem. Thanks!