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/node creates duplicate Transactions #15830

Open
3 tasks done
enixsoft opened this issue Mar 26, 2025 · 17 comments
Open
3 tasks done

@sentry/node creates duplicate Transactions #15830

enixsoft opened this issue Mar 26, 2025 · 17 comments
Assignees
Labels
Bug getsentry/sentry-javascript Package: node Issues related to the Sentry Node SDK

Comments

@enixsoft
Copy link

enixsoft commented Mar 26, 2025

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

9.9.0

Framework Version

No response

Link to Sentry event

No response

Reproduction Example/SDK Setup

// middleware

import * as Sentry from '@sentry/node'

const activeSpan = Sentry.getActiveSpan()
const rootSpan = activeSpan && Sentry.getRootSpan(activeSpan)

if (rootSpan) {
// ctx.routeKey is string, for example "GET-/users"
Sentry.updateSpanName(rootSpan, ctx.routeKey || 'unknown')
}

Steps to Reproduce

I am using AdonisJS v6 framework with the Sentry integration rlanz/sentry v0.3.3 and @sentry/node package v9.9.0.

In my reproduction example there is a code from middleware that runs on every request and it's supposed to update the root span (transaction) name. The root span is expected to always be http.server operation with origin auto.http.otel.http.

In my Sentry dashboard, I see transactions on the sampled events with the correct updated name, they contain spans and have user attached, but I also see events from another transaction which is using the automatically generated name, but always without any spans and without user. Those duplicate transactions are easy to notice because the names are similar, the events are traced at the same time with nearly the same duration. Also the data (like request query string, headers, cookies) is same in both, so I assume that it's a duplicated transaction from the exact same request.

There is also other difference I see comparing the JSON of both sampled events which might explain this, the transaction with updated name by middleware has sentry.source: custom and "transaction_info": { "source": "custom" } in its data. And the duplicate has sentry.source: url and "transaction_info": { "source": "sanitized" }.

Expected Result

Only one transaction (the one with updated name) will appear in Sentry dashboard for specific request.

Actual Result

Transactions seem to be duplicated.

Image

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 26, 2025
@github-actions github-actions bot added the Package: node Issues related to the Sentry Node SDK label Mar 26, 2025
@s1gr1d
Copy link
Member

s1gr1d commented Mar 27, 2025

Thanks for opening this issue. It could be that this is the same or similar issue like #15803.

We're going to take a look at this.

@s1gr1d
Copy link
Member

s1gr1d commented Mar 27, 2025

@enixsoft Would you be able to provide a small reproduction example?

@enixsoft
Copy link
Author

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 28, 2025
@lforst
Copy link
Member

lforst commented Mar 31, 2025

Hi, since this issue is about @rlanz/sentry which we don't maintain, I recommend you raise this with that project instead.

@enixsoft
Copy link
Author

@lforst
Hi, @rlanz/sentry is only a simple wrapper using @sentry/node that initializes Sentry and is supposed to update the root span (transaction) name using the code in Reproduction Example.

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 31, 2025
@lforst
Copy link
Member

lforst commented Mar 31, 2025

@enixsoft makes sense, however, we have no reason to believe that @sentry/node is at fault because we do not create span names with hyphens in between method and path. It's likely that @rlanz/sentry is simply feeding bad data into @sentry/node.

@enixsoft
Copy link
Author

enixsoft commented Mar 31, 2025

@lforst
The name with hyphens is the correct one, that's what the code in Reproduction Example is supposed to do, it's a middleware that updates the root span's name according to AdonisJS conventions instead of relying on the automatically chosen name.

The automatically created transaction with name without hyphens is the one that doesn't have all the data and the one I consider an unnecessary duplicate for the same request and route.

My understanding of this issue is that:

  1. Sentry after initialization automatically patches node's http/https modules, which is what I see in logs:
    Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
    Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
    Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
    Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }

  2. When application receives a request, the root span gets automatically created and named by the instrumentation.

  3. The request then goes through the middleware which contains the code in the Reproduction Example, where the root span's name gets updated to the name I want.

  4. After the request is finished, the tracing data is sent to the Sentry server and I can view it in the Insights -> Backend dashboard.

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 31, 2025
@lforst
Copy link
Member

lforst commented Mar 31, 2025

It's possible that not all requests are routed through that middleware which would mean that not all span names are updated. (or rather that that code path is not always hit but you know what I mean)

@enixsoft
Copy link
Author

@lforst

I think I found the cause of the problem. The automatic instrumentation module patching can run more than once and when it does, this is when the duplicated transactions start to happen. I have updated the reproduction example in #15830 (comment) and added a preload file which imports axios (and axios imports http and https modules and this triggers the patching). Both modules are first patched right after the Sentry.init() call, then again by axios import.

This is what I get by running the reproduction example and sending one request (GET /test/span/123):

[ info ] starting HTTP server...
Sentry Logger [log]: Initializing Sentry: process: 125703, 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: LocalVariablesAsync
Sentry Logger [log]: Integration installed: Context
Sentry Logger [log]: Integration installed: ChildProcess
Sentry Logger [log]: Integration installed: ProcessSession
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: Hapi
Sentry Logger [log]: Integration installed: Koa
Sentry Logger [log]: Integration installed: Connect
Sentry Logger [log]: Integration installed: Tedious
Sentry Logger [log]: Integration installed: GenericPool
Sentry Logger [log]: Integration installed: Kafka
Sentry Logger [log]: Integration installed: Amqplib
Sentry Logger [log]: Integration installed: LruMemoizer
Sentry Logger [log]: Integration installed: VercelAI
Sentry Logger [log]: Running in ESM mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Axios version: 1.8.4
╭──────────────────────────────────────────────────╮
│                                                  │
│    Server address: http://localhost:3333        │
│    Watch Mode: HMR                               │
│    Ready in: 497 ms                              │
│                                                  │
╰──────────────────────────────────────────────────╯
[14:13:43.545] INFO (125703): started HTTP server on localhost:3333
Sentry Logger [debug]: @sentry/instrumentation-http http instrumentation for incoming request
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http http instrumentation incomingRequest
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: < unknown op >
  name: GET
  ID: 943354c9514d4f51
Sentry Logger [debug]: @sentry/instrumentation-http http instrumentation for incoming request
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http http instrumentation incomingRequest
Sentry Logger [log]: [Tracing] Starting sampled root span
  op: < unknown op >
  name: GET
  ID: 8301b5c667dc7c63
Sentry Logger [log]: [Tracing] Inheriting parent's sampled decision for test/span/123: true
Sentry Logger [log]: [Tracing] Starting sampled span
  op: < unknown op >
  name: test/span/123
  ID: 4d818da508eafdbf
  parent ID: 8301b5c667dc7c63
  root ID: 8301b5c667dc7c63
  root description: GET-/test/span/:id
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" span "test/span/123" with ID 4d818da508eafdbf
Sentry Logger [debug]: Recorded request session with status: ok
Sentry Logger [debug]: Opened new request session aggregate.
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "GET" with ID 943354c9514d4f51
Sentry Logger [debug]: Recorded request session with status: ok
Sentry Logger [log]: [Tracing] Finishing "< unknown op >" root span "GET-/test/span/:id" with ID 8301b5c667dc7c63
Sentry Logger [log]: SpanExporter exported 3 spans, 0 spans are waiting for their parent spans to finish

And this is how it looks like in dashboard:

Image

Is it possible to make sure that the http and https module patching happens only once or can it be forced during the initialization of Sentry, so it is not triggered by import of the modules?

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 31, 2025
@lforst
Copy link
Member

lforst commented Mar 31, 2025

It is paramount to only run Sentry.init() and instrumentations once within a process.

@enixsoft
Copy link
Author

enixsoft commented Mar 31, 2025

@lforst

Sentry.init() gets called only once. The automatic instrumentations are triggered by imports.

I am asking if there is a possibility on your side to ensure the patching of the http and https node modules by @sentry/instrumentation-http and @opentelemetry_sentry-patched/instrumentation-http is only applied once, because when it is, everything behaves as expected (no duplicated transactions).

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 31, 2025
@andreiborza
Copy link
Member

Hm, otel should already take care of not double patching. You're saying it behaves as expected when not double patched, have you tried patching anything on your side? Mind sharing?

@enixsoft
Copy link
Author

enixsoft commented Apr 2, 2025

@andreiborza
I don't know how would I patch those http and https modules manually. I only know that import of the module triggers the patching, so all I did in code is import both modules right after initializing Sentry. That triggers the patch but if there is another import in the code elsewhere, it triggers the patch again, leading to this whole issue. You can test that in my reproduction example.

Is there another or better way to achieve this?

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Apr 2, 2025
@lforst
Copy link
Member

lforst commented Apr 2, 2025

I tried looking at your repro, but I have no idea what is going on and what is called where. We're diverging pretty far from how we intend people to use the node SDK here.

My best guess is that somehow there are two processes of some sort running and one is properly instrumented and the other one isn't - potentially due to ESM. I understand way to little though how AdonisJS works though to be able to make a judgment call for that.

@enixsoft
Copy link
Author

enixsoft commented Apr 3, 2025

@lforst
I made a simple node.js Express repo:
https://github.com/enixsoft/express-sentry-example

The same behaviour happens in it, when you initialize Sentry and after that you have multiple http and https module imports (in my example I import them directly and then I import axios which also imports them, you can test this with ENV variable), you'll get multiple patches and duplicate transactions:

Sentry Logger [log]: Running in ESM mode.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for diag v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for trace v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for propagation v1.9.0.
Sentry Logger [debug]: @opentelemetry/api: Registered a global for context v1.9.0.
Importing http...
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Importing https...
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Importing axios...
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'http' }
Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Sentry Logger [debug]: @sentry/instrumentation-http Applying instrumentation patch for nodejs core module on require hook { module: 'https' }
Axios version: 1.8.4
Importing express app...
Sentry Logger [debug]: @sentry/instrumentation-express-v5 Applying instrumentation patch for module on require hook {
  module: 'express',
  version: '5.1.0',
  baseDir: '/home/user/git/express-sentry-example/node_modules/.pnpm/express@5.1.0/node_modules/express'
}
Server running on port 3333, environment: development

Image

@smeubank
Copy link
Member

smeubank commented Apr 8, 2025

Thanks for opening this issue. It could be that this is the same or similar issue like #15803.

We're going to take a look at this.

@s1gr1d any update if this is duplicate?

@lforst
Copy link
Member

lforst commented Apr 8, 2025

@smeubank It could be related.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug getsentry/sentry-javascript Package: node Issues related to the Sentry Node SDK
Projects
Status: No status
Development

No branches or pull requests

6 participants