[express] express auto instrumentation no longer works if you enable profiling

[shellmayr]

After following the docs and https://docs.sentry.io/platforms/javascript/guides/express/profiling/
once the profiling is enabled, a message gets shown saying:

[Sentry] express is not instrumented. This is likely because you required/imported express before calling `Sentry.init()`.

Also express instrumentation doesn't work.

Once the profiling is disabled, express instrumentation works.

[shellmayr]

Talked with @vgrozdanic to find out more about how the bug occured - just auto-instrumenting sentry with profiling in express triggered this issue for them. He mentioned there could also be an interaction with Drizzle ORM.

Going through the different scenarios to reproduce:

1. Without profiling -> an issue is created 🟢
2. With startProfiler() and an error outside of the profiled section, an issue is created 🟢
3. With startProfiler() and an error inside the profiled section, there seems to be an infinite loop? Express doesn’t return a response to the browser, no data sent to sentry, no issue created 🔴
4. With profilesSampleRate=1.0 in instrument.js and startProfiler(), error inside the profiled section, an issue is created 🟢

Having Drizzle ORM or not did not change the results.

Tested Spans/Tracing with and without importing profiling, and I get this error:

• Without profiling I get a nice trace with express middleware 🟢 Trace

import * as Sentry from "@sentry/node";
//import { nodeProfilingIntegration } from "@sentry/profiling-node";

Sentry.init({
  dsn: "[INSERT DSN]",
  integrations: [
    //nodeProfilingIntegration(),
  ],
  // Tracing
  tracesSampleRate: 1.0, //  Capture 100% of the transactions
  //profilesSampleRate: 1.0,
  debug: true
});

• With profiling added to the instrumentation.js, there are no spans from express 🔴 Trace
  • The error message in node is [Sentry] express is not instrumented. This is likely because you required/imported express before calling Sentry.init().

import * as Sentry from "@sentry/node";
import { nodeProfilingIntegration } from "@sentry/profiling-node";

Sentry.init({
  dsn: "[INSERT DSN]",
  integrations: [
    nodeProfilingIntegration(),
  ],
  // Tracing
  tracesSampleRate: 1.0, //  Capture 100% of the transactions
  profilesSampleRate: 1.0,
  debug: true
});

Code: express-repro.zip

[Lms24]

I'm fairly certain this has something to do with profiling-node defining and using require calls in an otherwise ESM application. AFAIK this is necessary because there's no other way to load the binaries (cc @JonasBa - correct?). Not sure why this inhibits other instrumentation.

What we know for sure from the log message is that our SDK-internal isCjs utility also flags the app as CJS (somewhat correctly I guess, due to require, but not what we want or users would expect):

sentry-javascript/packages/node/src/utils/ensureIsWrapped.ts

Lines 23 to 33 in af773b1

	if (isCjs()) {
	// eslint-disable-next-line no-console
	console.warn(
	`[Sentry] ${name} is not instrumented. This is likely because you required/imported ${name} before calling \`Sentry.init()\`.`,
	);
	} else {
	// eslint-disable-next-line no-console
	console.warn(
	`[Sentry] ${name} is not instrumented. Please make sure to initialize Sentry in a separate file that you \`--import\` when running node, see: https://docs.sentry.io/platforms/javascript/guides/${name}/install/esm/.`,
	);
	}

[Lms24]

Ok I think I found out what's going in: We only register the import-in-the-middle hook if our isCJS check returns false which it doesn't, due to the definedness of require.

This is also apparent by an earlier log:

Sentry Logger [log]: Running in CommonJS mode.

So the ESM modules (like express) cannot be instrumented.

I'm not sure though about the implication of this. Does this mean profiling exclusively works in CJS apps 🤔

[lforst]

What I don't get is, that for some reason error monitoring is affected 😵

[Lms24]

PR that hopefully fixes the missing instrumentation part: #13834

[Lms24]

What I don't get is, that for some reason error monitoring is affected 😵

@shellmayr I could not reproduce the error part. I tried with automatic profiling as well as with Sentry.profiler.startProfiler() but I always got errors in Sentry. Can you share a specific version of the repro where you don't get errors? Just trying to identify what's going on cause I don't see an immediate reason as to why us wrongfully detecting ESM/CJS would lead to errors not being caught.

[JonasBa]

@Lms24 @shellmayr just wanted to let you know that this is the first thing I'm looking at. I opened up a separate draft PR where I'm trying to scope createRequire. Unfortunately the e2e test I added wont pass, even though we don't store the result of createRequire call on globalThis. This makes me think its either not forcing mjs at runtime, or there is something else like the build step that provides it. In any case, I'm looking into this and will keep you updated.

[shellmayr]

Thanks @JonasBa! 🙏

@shellmayr I could not reproduce the error part. I tried with automatic profiling as well as with Sentry.profiler.startProfiler() but I always got errors in Sentry. Can you share a specific version of the repro where you don't get errors? Just trying to identify what's going on cause I don't see an immediate reason as to why us wrongfully detecting ESM/CJS would lead to errors not being caught.

@Lms24 regarding this point, I think it breaks mostly when it is wrongly configured - the above test cases show that unless there is an error in the profiled section, the error monitoring works, so just configuring the integration does not seem to cause this behaviour. Let's get this fixed first and then see if the problem persists.