Performance issues caused by Sentry.Handlers.requestHandler middleware, about 40% higher latency

[olessavluk]

Is there an existing issue for this?

• I have checked for existing issues https://github.com/getsentry/sentry-javascript/issues
• I have reviewed the documentation https://docs.sentry.io/
• I am using the latest SDK release https://github.com/getsentry/sentry-javascript/releases

How do you use Sentry?

Self-hosted/on-premise

Which SDK are you using? If you use the CDN bundles, please specify the exact bundle (e.g. bundle.tracing.min.js) in your SDK setup.

@sentry/node

SDK Version

7.45.0

Framework Version

No response

Link to Sentry event

No response

SDK Setup

Sentry.init({
  enabled: isProduction(),
  debug: !isProduction(),
  dsn: "<hidden>",
  environment: process.env.NODE_ENV,
  integrations: [
    // GraphQL erorrs have some custom properties that might be usefull for debugging
    new ExtraErrorDataIntegration({
      // Limit of how deep the object serializer should go. Anything deeper than limit will
      // be replaced with standard Node.js REPL notation of [Object], [Array], [Function] or
      // a primitive value. Defaults to 3.
      depth: 3,
    }),
  ],
})

const app = express()
app.use(Sentry.Handlers.requestHandler())
// ... more middlewares
app.use(Sentry.Handlers.errorHandler())
app.listen(...)

Steps to Reproduce

added app.use(Sentry.Handlers.requestHandler())

Expected Result

No "visible" impact on server cpu usage & response latency

Actual Result

CPU usage slightly increased, significant increatese in latency

[olessavluk]

A bit context about server internals:

It's an express.js server using "apollo graphql". Looking at chrome devtools profile alot of time was spent in node:domain

Maybe this related to pattern where almost every field returned by server create new promise, something like:

const getDataThen = fn => (id, _, { dataSources }) =>
  dataSource.getById(id).then(res => fn(res, dataSources))
  
 // ...
    display_order: getContractThen(obj => obj.display_order),
    hidden: getContractThen(obj => obj.hidden),
    id: id => id,
    info: getContractThen(obj => obj.info),
    market_id: getContractThen(obj => obj.market_id),
    market: getContractThen(obj => obj.market_id),
    name: getContractThen(obj => obj.name),
  }

I imagine with ~1-3MB of response this will create huge amount of promises internally?

[AbhiPrasad]

Hey @olessavluk - domains have a hard time dealing with the memory pressure of a large amount of promises, so that is probably the reason why this is happening.

Can you extract the multiple getContractThen into a single call to get the promise? That should make things much better.

We have an open issue to migrate away from domains and use async_hooks internally instead: #3660, so backlogging this for now, but we will start work on this soon.

[AbhiPrasad]

Opened #7691 - we're going to start exploring it next week.

[AbhiPrasad]

Hey @olessavluk, could you try upgrading to the 7.48.0 release of the JS SDK and seeing if there are any changes?

We switched from using domains to AsyncLocalStorage, so this should be improved.

[olessavluk]

Looks good, much better than previous version 👍
Maybe slight increase in p90 latency, but hard to tell if due to sentry or different load

[AbhiPrasad]

Great! We're gonna make a couple more changes to improve perf here, so gonna leave this open for now. Stay tuned!

[AbhiPrasad]

Alright there were some changes made to stacktrace parsing and some other code - so going to close this for now.

We'll keep monitoring and improving this though!