getsentry / sentry-javascript

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

Replacement for Sentry.Integrations.Apollo() #12887

Open RodoVJ opened 4 months ago

RodoVJ commented 4 months ago

Problem Statement

I'm trying to upgrade to v8 of @sentry/node. However the Apollo integration was deprecated and can't find a replacement for it. I can see a replacement for other integrations have been made here https://github.com/getsentry/sentry-javascript/blob/develop/MIGRATION.md but there is no mention of the Apollo integration.

Solution Brainstorm

I'd expect the v8 migration to provide an alternative to the Apollo integration that was available in v7.

AbhiPrasad commented 4 months ago

Hey @RodoVJ - you don't need the explicit Sentry.Integrations.Apollo anymore, this has been replaced by the graphl integration, which is automatically enabled in the SDK

https://docs.sentry.io/platforms/javascript/guides/node/configuration/integrations/graphql/

We need to update the migration docs!

AbhiPrasad commented 4 months ago

Opened https://github.com/getsentry/sentry-javascript/pull/12889 to track migration docs changes!

RodoVJ commented 4 months ago

@AbhiPrasad Thank you for getting back to me. With this change I am no longer able to get Apollo/GraphQL trace information to Sentry with v8 but it works with v7. I wonder if this could be a bug or maybe a configuration issue on my side.

I'm initiating Sentry in a instrument.ts file which I'm then importing to the entry file with import { sentry } from '../instrument' (My app and our typescript config does not support require).

This is what how I'm initiating Sentry:

export const sentry = Sentry.init({
  dsn',
  includeLocalVariables: true,
  enableTracing: true,
  integrations: [
    Sentry.httpIntegration(),
    Sentry.expressIntegration(),
    Sentry.graphqlIntegration(),
    Sentry.postgresIntegration(),
    Sentry.captureConsoleIntegration({ levels: ['error'] }),
  ],

  tracesSampleRate: environment.production ? 0.2 : 1.0,

});

AbhiPrasad commented 4 months ago

you should be able to simplify your SDK config like so:

export const sentry = Sentry.init({
  dsn,
  includeLocalVariables: true,
  integrations: [
    Sentry.captureConsoleIntegration({ levels: ['error'] }),
  ],
  tracesSampleRate: environment.production ? 0.2 : 1.0,
});

you don't need to specify enableTracing, setting a tracesSampleRate is enough for that.

you also don't need to include httpIntegration, expressIntegration, graphqlIntegration, and postgresIntegration, these are included by default.

Alright to debug your SDK setup. First off, could you add debug: true to your SDK init call? That will allow us to see if integrations are getting registered properly.

Second, you mentioned that your TS config does not support require. Does your transpiled JavaScript (what your TS turns into) have import/export (ESM) or require/module.exports (CJS) in it?

You may need to reference these docs to adjust installation based on if your code is ESM or CJS: https://docs.sentry.io/platforms/javascript/guides/node/install/

RodoVJ commented 4 months ago

@AbhiPrasad Thanks for the tips on simplifying the integrations!

My transpiled JavaScript has require/module.exports (CJS)

When I include debug: true this is what I get when initializing the app:

Sentry Logger [log]: Initializing Sentry: process: 4108, thread: main.
Sentry Logger [log]: Integration installed: InboundFilters
Sentry Logger [log]: Integration installed: FunctionToString
Sentry Logger [log]: Integration installed: LinkedErrors
Sentry Logger [log]: Integration installed: RequestData
Sentry Logger [log]: Integration installed: Console
Sentry Logger [log]: Integration installed: Http
Sentry Logger [log]: Integration installed: NodeFetch
Sentry Logger [log]: Integration installed: OnUncaughtException
Sentry Logger [log]: Integration installed: OnUnhandledRejection
Sentry Logger [log]: Integration installed: ContextLines
Sentry Logger [log]: Integration installed: LocalVariables
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: Modules
Sentry Logger [log]: Integration installed: Express
Sentry Logger [log]: Integration installed: Fastify
Sentry Logger [log]: Integration installed: Graphql
Sentry Logger [log]: Integration installed: Mongo
Sentry Logger [log]: Integration installed: Mongoose
Sentry Logger [log]: Integration installed: Mysql
Sentry Logger [log]: Integration installed: Mysql2
Sentry Logger [log]: Integration installed: Redis
Sentry Logger [log]: Integration installed: Postgres
Sentry Logger [log]: Integration installed: Nest
Sentry Logger [log]: Integration installed: Hapi
Sentry Logger [log]: Integration installed: Koa
Sentry Logger [log]: Integration installed: Connect
Sentry Logger [log]: Integration installed: CaptureConsole
Sentry Logger [log]: Running in CommonJS mode.                                                                                             'https'  
Sentry Logger [debug]: @opentelemetry/instrumentation-express Applying instrumentation patch for module on require hook {re hook { module: '
  module: 'express',
  version: '4.19.2',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\express'
}entry Logger [debug]: @opentelemetry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: '

Sentry Logger [debug]: @opentelemetry/instrumentation-graphql Applying instrumentation patch for nodejs module file on require hook {le\inde
  module: 'graphql',
  version: '15.8.0',
  fileName: 'graphql\\language\\parser.js',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\graphql'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-graphql Applying instrumentation patch for nodejs module file on require hook {
  module: 'graphql',
  version: '15.8.0',
  fileName: 'graphql\\validation\\validate.js',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\graphql'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-graphql Applying instrumentation patch for nodejs module file on require hook {
  module: 'graphql',
  version: '15.8.0',
  fileName: 'graphql\\execution\\execute.js',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\graphql'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-ioredis Applying instrumentation patch for module on require hook {
  module: 'ioredis',
  version: '5.4.1',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\ioredis'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-pg Applying instrumentation patch for module on require hook {
  module: 'pg-pool',
  version: '3.5.2',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\pg-pool'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-pg Applying instrumentation patch for module on require hook {
  module: 'pg',
  version: '8.8.0',
  baseDir: 'C:\\Users\\Owner1\\Documents\\CHASER_JOB\\development\\web-app\\node_modules\\pg'
}
Sentry Logger [debug]: @opentelemetry/instrumentation-pg Patching pg.Client.prototype.query                                                s:65:14) 
fetch.ts:54:7)
Sentry Logger [error]: Skipped sending event because buffer is full.lopment\web-app\node_modules\@sentry\node\src\integrations\node-fetch.ts        
    at emitExperimentalWarning (node:internal/util:226:11)
Sentry Logger [error]: Skipped sending event because buffer is full.
    at new FetchInstrumentation (C:\Users\Owner1\Documents\CHASER_JOB\development\web-app\node_modules\opentelemetry-instrumentation-fetch-n        
Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [error]: Skipped sending event because buffer is full.

Sentry Logger [log]: Local variables rate-limit exceeded. Disabling capturing of caught exceptions for 10 seconds.
NOTICE:  extension "uuid-ossp" already exists, skipping

Sentry Logger [error]: Skipped sending event because buffer is full.

-- Running API on port 3000
Sentry Logger [log]: Local variables rate-limit lifted.

Btw I tried removing includeLocalVariables: true based on the buffer full errors but I am still not getting any Apollo/Graphql transactions

lforst commented 4 months ago

@RodoVJ can you share some more information on what happened in your application when these logs were produced? Is it all during startup?

Weird idea, but can you try remove the captureConsoleIntegration? I think it might be flooding events.

RodoVJ commented 4 months ago

@lforst It was all during startup. Also removing captureConsoleIntegration doesn't make a difference. By the way, I'm not using the node --import instrument.mjs method mentioned in the migration docs since my team is using a monorepo and that set up would be a bit more complicated. Also does it matter that I'm specifying the instrument.ts file as a typescript file?

AbhiPrasad commented 4 months ago

Also does it matter that I'm specifying the instrument.ts file as a typescript file

you are required to use node --import if you are using ESM, but since your code transpiles to CJS you are fine.

We can see this is okay because the sdk logs out Sentry Logger [log]: Running in CommonJS mode

Also removing captureConsoleIntegration doesn't make a difference

From the logs the internal queue the SDK uses to send events seems to be full, hence it makes sense that no performance data is being sent.

if you add beforeSend and log out events, what gets shown?

Sentry.init({
  beforeSend: (event) => {
    console.log(event);
    return event;
  },
});

What version of Node.js are you using?

RodoVJ commented 4 months ago

We are using Node v.18.8. However I am now using v.18.19 locally since I was following the migration docs.

I added the beforeSend option but nothing actually seems to be logged. Also I ran an operation that would normally cause GraphQL events to be sent and this is what Sentry outputted. I don't see any GraphQL or Postgres events being registered

Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest
Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest
Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on response()
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on end()
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on request close()
Sentry Logger [debug]: @opentelemetry/instrumentation-http https instrumentation outgoingRequest
Sentry Logger [debug]: @opentelemetry/instrumentation-http http.ClientRequest return request
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on response()
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on end()
Sentry Logger [debug]: @opentelemetry/instrumentation-http outgoingRequest on request close()
Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest
Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest
Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest
Lms24 commented 4 months ago

@RodoVJ any chance you could provide a minimal reproduction that we could use to further investigate this issue?

Based on the logs you posted it seems like our SDK is able to patch graphql correctly but for some reason, spans are not started/added. I'm wondering if this is still a timing issue. Can you confirm that Sentry.init is being called before any other require statement in your app is evaluated?

Lms24 commented 4 months ago

Oh another thing I jut noticed: Since we're looking for missing spans, please log the event sent in beforeSendTransaction rather than beforeSend. beforeSend will only be called for error events.

RodoVJ commented 4 months ago

@Lms24 I apologize for the late reply, I will get you this information by tomorrow :). I appreciate the support!

RodoVJ commented 4 months ago

@Lms24 I think I figured out what the issue is. I included beforeSendTransaction to check the transaction being processed and these are the logs I get for a GraphQL action

Sentry Logger [debug]: @opentelemetry/instrumentation-http http instrumentation incomingRequest
BEFORE SEND: POST /graphql

The event is being sent, the problem comes with how the transaction is being displayed on Sentry. On Sentry I can only see the transaction as POST /graphql but we have an Apollo plugin to rename transactions to give them more information.

I did a small test like this so to check this behavior:

  beforeSendTransaction: (event) => {
    console.log(`BEFORE SEND: ${(event.transaction)}`);
    console.log(`BEFORE SEND: ${(event.event_id)}`);
    Sentry.getCurrentScope().setTransactionName("JUST TESTING");
    console.log(Sentry.getCurrentScope())
    return event;
  },

This does change the transaction name (based on logging the current scope) but it's not reflected in Sentry. Something interested to note is that when I compare the event ID logged and the one on Sentry, they are the same. But when I compare the trace ID's they are not the same. I'm getting the trace id from printing the current scope. Any insight would be appreciated!

Lms24 commented 4 months ago

This does change the transaction name (based on logging the current scope) but it's not reflected in Sentry

Calling Sentry.getCurrentScope().setTransactionName no longer has influence on the name of the transaction event you're currently logging out. The scope's transactionName and the name of the active root span have been decoupled in https://github.com/getsentry/sentry-javascript/issues/10846 (if you wanna read up on details).

Believe me, I'm more than unhappy about the naming colission here but our move away from calling the root span "transaction" will hopefully alleviate this a bit in the future.

we have an Apollo plugin to rename transactions to give them more information

Did you use this before updating to v8 as well? Does it also call Sentry.getCurrentScope().setTransactionName?

If you have such a plugin and it updates the name before the transaction event is sent, here's how you can manually update the root span's (formerly known as transaction) name:

const span = Sentry.getActiveSpan();
if (span) {
  const rootSpan = Sentry.getRootSpan(span);
  rootSpan.updateName('customName');
}
// set this to have the same transaction name reported for error events
Sentry.getCurrentScope().setTransactionName('customName')

I would recommend you call both - span.updateName as well as scope.setTransactionName to the same value generally. It's what we do in our instrumentation as much as we can.

But when I compare the trace ID's they are not the same

This is strange but possibly expected. Generally, you should get one trace id for all events happening throughout one server request life cycle. This might not be the same trace id as the one on the scope's propagationContext since it's handled by openTelemetry.

RodoVJ commented 4 months ago

@Lms24

Did you use this before updating to v8 as well? Does it also call Sentry.getCurrentScope().setTransactionName?

Before v8 we used the method below but configureScope was deprecated in v8.

  Sentry.configureScope((scope) => {
    scope.setTransactionName(`GraphQL ${ctx.request.operationName}`);
  });

If you have such a plugin and it updates the name before the transaction event is sent, here's how you can manually update the root span's (formerly known as transaction) name:

I tried this method in the plugin and when I log the rootSpan I can see that the name property is updated. However when I check the Sentry performance dashboard I can't see the custom name under transactions. So Iogged the rootSpan in the beforeSendTransaction method and to my surprise the name of the span was reverted back to POST /graphql.

In fact I tried changing the span's name in the beforeSendTransaction method directly like below but when logging the span, the name was not updated to the custom name. Why do you think that is?

  beforeSendTransaction: (event) => {
    const customName = 'JUST TESTING';

    const span = Sentry.getActiveSpan();
    if (span) {
      const rootSpan = Sentry.getRootSpan(span);
      rootSpan.updateName(customName);
      console.log(Sentry.getRootSpan(span)) // name is still set to `POST /graphql`
    }

    Sentry.getCurrentScope().setTransactionName(customName);
    return event;
  },

This is strange but possibly expected. Generally, you should get one trace id for all events happening throughout one server request life cycle. This might not be the same trace id as the one on the scope's propagationContext since it's handled by openTelemetry.

You are right about this, I think that trace id is from openTelemtry. When logging the rootSpan instead, the trace id does match with what I see on Sentry.

Lms24 commented 4 months ago

Ahh this might be related to our name inferral method. Not sure though yet. I'll check on Monday.

RodoVJ commented 3 months ago

Hi @Lms24 any updates on this?

Lms24 commented 3 months ago

Still gotta check the name inferral I was mentioning earlier. But if you're able to overwrite the name to what you want it to be at the time when beforeSendTransaction is invoked, that would be a solution, too. You need to change the code a little though:

  beforeSendTransaction: (event) => {
    const customName = getYourName();

    // explanation: Your root span's name becomes the `event.transaction` property when 
    // we convert the span to an event in the SDK
    event.transaction = customName; 

    return event;
  },

Side note: Calling getActiveSpan inside beforeSendTransaction won't give you the span that's going to be sent. It might give you no span or another one that's active at this time.

Lms24 commented 3 months ago

What you can also try, in case beforeSendTransaction doesn't work for your use case, is to disable our automatic span name inferral. I think it still interferes with your custom plugin. To avoid any inferral, do this:

const span = Sentry.getActiveSpan();
if (span) {
  const rootSpan = Sentry.getRootSpan(span);
  rootSpan.updateName('customName');
  rootSpan.setAttribute('sentry.skip_span_data_inference', true);
}
// set this to have the same transaction name reported for error events
Sentry.getCurrentScope().setTransactionName('customName')

Background: I think that your root span is created by our httpInstrumentation which by default only assigns very basic names. Basically just GET or POST. We have some inferral logic in place, to update the root span name based on checking span attributes and related data later on to produce a more meaningful root span name (= transaction name). In your case, our inferral logic will produce POST /graphql for you. Unfortunately, this limits setting a custom name like what you're trying to do. If you set the sentry.skip_span_data_inference attribute, we'll no longer try to infer the name but just leave the already set name untouched.

trevorr commented 3 months ago

@Lms24 I tried your last suggestion above, using rootSpan.updateName, but I still end up with POST /graphql as the transaction name. I can change the transaction name using beforeSendTransaction, but I'm not sure how to attach the GraphQL operation name to the event such that I can set it as the transaction name. Any ideas?

trevorr commented 3 months ago

This works, but it seems pretty inefficient:

beforeSendTransaction(event) {
  if (event.spans) {
    for (const span of event.spans) {
      const operationName = span.data?.["graphql.operation.name"];
      if (typeof operationName === "string") {
        event.transaction = operationName;
        break;
      }
    }
  }
  return event;
},
andreiborza commented 3 months ago

@trevorr thanks for providing a workaround. I've filed an enhancement issue where we could potentially tackle this at the integration level.