Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sentry creates three traces for a single http request (ESM, custom opentelemetry setup) #14065

Closed
3 tasks done
nlochschmidt opened this issue Oct 23, 2024 · 9 comments
Closed
3 tasks done
Labels
Package: node Issues related to the Sentry Node SDK Package-Meta: OpenTelemetry

Comments

@nlochschmidt
Copy link

nlochschmidt commented Oct 23, 2024

Is there an existing issue for this?

How do you use Sentry?

Sentry Saas (sentry.io)

Which SDK are you using?

@sentry/node

SDK Version

8.35.0

Framework Version

hapi 21.3.10

Link to Sentry event

No response

Reproduction Example/SDK Setup

https://github.com/nlochschmidt/sentry-duplicate-tracing-bug

Steps to Reproduce

  1. I've setup Sentry and a custom otel setup as described in the docs we are not using Sentry for tracing but another service
  2. Running the server I can see from the logs that instrumentations are setup
  3. When I call the server e.g. curl localhost:3000 I get a spanId and traceId from inside the handler
  4. The ConsoleSpanExporter will print the traces and spans collected after a short time.

Expected Result

I expect to get a single trace with two spans (one for http and one for hapi).

Actual Result

What actually happens is that there are three traces and only one of them (traceId: 9dbf48ed9eee5aa66cba36df77eef90b) has the two spans that are expected, while the other two traces have only a single http root span.

I can see some odd instrumentation scopes @opentelemetry_sentry-patched/instrumentation-http, but interestingly the @opentelemetry/instrumentation-http is on one of the traces with a single span.

Here is the output cleaned up a bit (full output in the example repo README):

{
  traceId: '9dbf48ed9eee5aa66cba36df77eef90b',
  id: '86279d018d1d20f4',
  parentId: 'bb6216be501f6924',
  instrumentationScope: {
    name: '@opentelemetry/instrumentation-hapi',
  },

  name: 'route - /',
  kind: 0,
  attributes: {
    'sentry.sample_rate': 1
  },
  status: { code: 0 },
}
{
  traceId: '04de96dc9304e6376ac87ffa038e53f4',
  id: 'e68a07918c660533',
  parentId: undefined,
  instrumentationScope: {
    name: '@opentelemetry/instrumentation-http',
  },
  name: 'GET',
  kind: 1,
  attributes: {
    'sentry.sample_rate': 1,
    'sentry.parentIsRemote': true,
  },
  status: { code: 0 },
}
{
  traceId: 'e82eb8fe28439cad4cb409199d1759f3',
  id: '01cf0d4b96a81e61',
  parentId: undefined,
  instrumentationScope: {
    name: '@opentelemetry_sentry-patched/instrumentation-http',
  },
  name: 'GET',
  kind: 1,
  attributes: {
    'sentry.sample_rate': 1,
    'sentry.parentIsRemote': true,
    'sentry.origin': 'auto.http.otel.http',
  },
  status: { code: 0 },
  events: [],
  links: []
}
{
  traceId: '9dbf48ed9eee5aa66cba36df77eef90b',
  id: 'bb6216be501f6924',
  parentId: undefined,
  instrumentationScope: {
    name: '@opentelemetry_sentry-patched/instrumentation-http',
  },
  name: 'GET',
  kind: 1,
  attributes: {
    'sentry.sample_rate': 1,
    'sentry.parentIsRemote': true,
    'sentry.origin': 'auto.http.otel.http',
  },
  status: { code: 0 },
}

It works as expected when removing Sentry

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 23, 2024
@github-actions github-actions bot added the Package: node Issues related to the Sentry Node SDK label Oct 23, 2024
@nlochschmidt
Copy link
Author

nlochschmidt commented Oct 23, 2024

8.34.0 only creates a single trace, so it looks like this is a regression in 8.35.0. The problem is still present in 8.36.0-beta.0.

Some more things that I tried

  • HttpIntegration({ spans: false }): This does remove the @opentelemetry_sentry-patched/instrumentation-http spans, but now I get a double span for @opentelemetry/instrumentation-http instead of a single one, and also any captured exceptions no longer have the request data. So no good.

  • Keep HttpIntegration from Sentry, but remove the HttpInstrumentation from OTEL: The one additional @opentelemetry/instrumentation-http span goes away and I am left with two @opentelemetry_sentry-patched/instrumentation-http spans. However captured exceptions still have the request data

  • Use HttpIntegration({spans: false}) and remove HttpInstrumentation from OTEL (combination of the two above): With this the request data on captured exceptions works, but I no longer get any spans (neither from http nor from hapi.

@nlochschmidt
Copy link
Author

@mydea could this be related to #13763?

The release notes for 8.35.0 mention a SentryHttpInstrumentation that could be used with OTEL instead of the HttpInstrumentation:

This change introduces a new SentryHttpInstrumentation to handle non-span related HTTP instrumentation, allowing it to
run side-by-side with OTel's HttpInstrumentation.

This sounds promising, however I don't think SentryHttpInstrumentation is exported from @sentry/node, and I haven't found documentation on how to use SentryHttpInstrumentation.

@s1gr1d
Copy link
Member

s1gr1d commented Oct 24, 2024

Hy, your guess is right. This change was introduced in 8.35.0 and we still need to update documentation (created an issue). You have to add the following now, so Sentry does not emit spans (only your custom setup).

Sentry.init({
  integrations: [Sentry.httpIntegration({ spans: false })]
})

As you wrote you get double spans when setting this to false: This should not happen and I would have to reproduce this with your example (thanks for providing this).

@Lms24
Copy link
Member

Lms24 commented Oct 24, 2024

Hey @nlochschmidt

So after hours of debugging and nearly loosing my mind, we found a solution. In your reproduction, two module.register() calls were made: one in the hooks.ts file, you --import when starting the app, and one in Sentry.init. I'm fairly confident that this caused the double wrapping of the http module, which caused duplicated spans. This, paired with Sentry.httpIntegration being enabled by default and therefore sending yet another root span/trace, brings us indeed to three traces/root spans.

To fix this:

  1. As you already found out, register Sentry.httpIntegration({ spans: false }) in your Sentry.init call. This brings us down to two traces
  2. Then, we need to take care of the double register calls. You have two options:
    • Rely on Sentry's register call:
      • Remove hooks.ts
      • remove the import "instrument.ts" line in index.ts
      • change your start script to node --import instrument.js index.js
    • Rely on your own register call:
      • Move the contents of hooks.ts to the top of instrument.ts
      • remove the import "instrument.ts" line in index.ts
      • change your start script to node --import instrument.js index.js
      • set registerEsmLoaderHooks: false in your Sentry.init options.

To sum up (we will update the Custom Otel Setup docs accordingly):

  • You should always only register the loader hook once. Either yourself or let Sentry take care of it.
  • Sentry still needs the Sentry.httpIntegration({spans: false}) for non-span related request handling, like isolating data and attaching request data to errors. This needs to be set explicitly because otherwise, we fall back to Sentry.httpIntegration({spans: true}) which creates another root span.

@nlochschmidt
Copy link
Author

@s1gr1d @Lms24 I was starting to loose my mind as well 😂 Thank you!

I can confirm that this works in the example project (with Sentry register call, with own register call).

It's interesting that the --import ./build/instrument.js is required to get the hapi instrumentation to work. The http instrumentation by itself works with a simple import "./instrument.js" at the top of the index.ts file and no --import. Very odd behavior.

Will try it in production next 🤞

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 24, 2024
@Lms24
Copy link
Member

Lms24 commented Oct 24, 2024

Http instrumentation works because it's a built-in module. All other instrumentations (node fetch being another exception) like hapi, express, pg, etc. need to be initialized beforehand (via --import loader).

@nlochschmidt
Copy link
Author

Quick update here. We have been working with Option 2 using the loader from opentelemetry with registerEsmLoaderHooks: false and Sentry.httpIntegration({ spans: false }). Tracing seems to be working again including hapi traces 👍 .

On the downside I don't think the context isolation in Sentry is working properly because we are getting the wrong tags on our reported errors. Since this did work in my example project it has probably something else to do with our setup.

I suggest to close this issue and I'll open another one if I can figure out the issue for that.

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Oct 25, 2024
@Lms24
Copy link
Member

Lms24 commented Oct 28, 2024

we are getting the wrong tags on our reported errors.

Can you elaborate on that? Do you mean that you get tags that should be assigned to events in request A to events in request B?

Also just to be sure: Are the wrong tags only added to errors? We were generally under the impression that request isolation should work with a custom otel setup for errors. There might be problems for spans/transactions but errors would be new 😅

Lms24 added a commit to getsentry/sentry-docs that referenced this issue Oct 31, 2024
updates the Custom Node Otel setup page by:

- showing how users can now add their own HttpInstrumentation (possible since we added `httpIntegration({spans: false})` in 8.35.0
- adding a section discussing ESM loaders and that only one loader hook (either their own or Sentry's) should be registered (we learned about this in getsentry/sentry-javascript#14065)

---------

Co-authored-by: Francesco Novy <[email protected]>
@getsantry getsantry bot moved this to Waiting for: Community in GitHub Issues with 👀 3 Nov 1, 2024
@nlochschmidt
Copy link
Author

@Lms24 So we found the issue. We are initializing Sentry in a shared library and had an issue where Sentry was initialized twice (once with it's own OTEL and once with ours). This somehow caused some of the errors to not get the route and transaction in them. After aligning the versions and removing the double initialization it works now.

@getsantry getsantry bot moved this from Waiting for: Community to Waiting for: Product Owner in GitHub Issues with 👀 3 Nov 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Package: node Issues related to the Sentry Node SDK Package-Meta: OpenTelemetry
Projects
Archived in project
Development

No branches or pull requests

4 participants