[@opentelemetry/instrumentation] require performance grows linearly with each instrumentation plugin

[mhassan1]

What version of OpenTelemetry are you using?

@opentelemetry/api@^1.1.0

What version of Node are you using?

v16.14.2

Please provide the code you used to setup the OpenTelemetry SDK

new NodeSDK({
  instrumentations: [getNodeAutoInstrumentations()]
})

What did you do?

const { getNodeAutoInstrumentations } = require('@opentelemetry/auto-instrumentations-node')
const { NodeSDK } = require('@opentelemetry/sdk-node')
const { performance: { now } } = require('perf_hooks')

new NodeSDK({
  instrumentations: [
    // toggle this
    getNodeAutoInstrumentations()
  ]
})

const start = now()

require('ajv') // or any moderately sized package

const duration = now() - start

console.log(Math.floor(duration), 'ms')

// with `instrumentations: [getNodeAutoInstrumentations()]` -> 100 ms
// with `instrumentations: []` -> 30 ms

What did you expect to see?

require should not be much slower when instrumentation is enabled

What did you see instead?

require is 3-5x slower when instrumentation is enabled

Additional context

• We have a large Node.js application that normally takes 20-30 seconds for startup. With getNodeAutoInstrumentations(), it takes 2.5 minutes.
• We noticed that time taken for require grows linearly with the number of enabled instrumentation plugins. In our large application, each additional instrumentation plugin adds 5-10 seconds to startup time.
• I could be way off, but I wonder if the problem could be related to the way @opentelemetry/instrumentation uses require-in-the-middle: since each instrumentation plugin invokes RITM, does the require function end up as a deeply nested patch on top of a patch on top of a patch?

[rauno56]

I could be way off, but I wonder if the problem could be related to the way @opentelemetry/instrumentation uses require-in-the-middle: since each instrumentation plugin invokes RITM, does the require function end up as a deeply nested patch on top of a patch on top of a patch?

No... you are actually absolutely right. We've been aware of this issue from the beginning, but haven't gotten around to fixing this.

RITM just patches require every time. Each last patch is added on top of the last one.

If there's no other takes I'd like to take a stab at this.

[dyladan]

I think the way to handle this is to have a single wrapper that catches all of the instrumented packages and looks up the appropriate instrumentation.

[dyladan]

Assigning priority 3 since this causes a performance issue in end user applications

[mhassan1]

@rauno56 Did you ever have a chance to look into this? I created a draft PR, and I'm looking for feedback: #3161.

[rauno56]

I had a rough WIP before other stuff took over my priority. Can take a look, or make my WIP available if you are interested.

[flex-jonghyen]

I have same issue. I made nextjs app with @ant-design/icons.
@ant-deisng/icons has 700+ icons. So, it makes super slow my app.

I post 2 pic. first one is turn on this, second one turn off when first response my next app page.
It makes almost double up

[mhassan1]

@dyladan Thanks for resolving this. When can we expect the next release of @opentelemetry/instrumentation?

[dyladan]

Today I hope

[mhassan1]

@dyladan I'm assuming there's something blocking the release. Is there anything I can do to help?

[legendecas]

Release in progress at #3340

[stebet]

@dyladan Is it possible this regressed in the lates OTel package release (1.8.0)? We saw a huge jump in the startup time of one of our bigger services after updating the packages yesterday

[dyladan]

Of course anything is possible, but I think it's unlikely that this particular issue regressed. Can you open a new issue for your startup time issue and provide your exact package versions and setup code?