fix(node): Fix vercel flushing logic & add test for it (#16208)

As pre-work for
#16178, actually add
a test for this (kind of). This showed that there was actually a
fundamental flaw here, as we looked as the `req` not the `res`, oops.

Author: mydea

dev-packages/node-integration-tests/suites/vercel/instrument.mjs

@@ -0,0 +1,13 @@
+import * as Sentry from '@sentry/node';
+import { loggingTransport } from '@sentry-internal/node-integration-tests';
+
+process.env.VERCEL = 'true';
+
+Sentry.init({
+  dsn: 'https://public@dsn.ingest.sentry.io/1337',
+  release: '1.0',
+  tracesSampleRate: 1.0,
+  transport: loggingTransport,
+  // We look at debug logs in this test
+  debug: true,
+});

dev-packages/node-integration-tests/suites/vercel/scenario.mjs

@@ -0,0 +1,13 @@
+import * as Sentry from '@sentry/node';
+import { startExpressServerAndSendPortToRunner } from '@sentry-internal/node-integration-tests';
+import express from 'express';
+
+const app = express();
+
+app.get('/test/express', (_req, res) => {
+  res.send({ response: 'response 1' });
+});
+
+Sentry.setupExpressErrorHandler(app);
+
+startExpressServerAndSendPortToRunner(app);

dev-packages/node-integration-tests/suites/vercel/test.ts

@@ -0,0 +1,53 @@
+import { afterAll, describe, expect } from 'vitest';
+import { cleanupChildProcesses, createEsmAndCjsTests } from '../../utils/runner';
+
+describe('vercel xxx', () => {
+  afterAll(() => {
+    cleanupChildProcesses();
+  });
+
+  createEsmAndCjsTests(__dirname, 'scenario.mjs', 'instrument.mjs', (createRunner, test) => {
+    test('should flush events correctly on Vercel', async () => {
+      const runner = createRunner()
+        .expect({
+          transaction: {
+            transaction: 'GET /test/express',
+          },
+        })
+        .start();
+      runner.makeRequest('get', '/test/express');
+      await runner.completed();
+
+      const actualLogs = runner.getLogs();
+
+      // We want to test that the following logs are present in this order
+      // other logs may be in between
+      const expectedLogs = [
+        'Sentry Logger [log]: @sentry/instrumentation-http Patching server.emit',
+        'Sentry Logger [log]: @sentry/instrumentation-http Handling incoming request',
+        'Sentry Logger [log]: @sentry/instrumentation-http Patching request.on',
+        'Sentry Logger [debug]: @opentelemetry_sentry-patched/instrumentation-http http instrumentation incomingRequest',
+        'Sentry Logger [log]: [Tracing] Starting sampled root span',
+        // later...
+        'Sentry Logger [log]: Patching response to flush on Vercel',
+        'Sentry Logger [log]: Patching res.end()',
+        // later...
+        'Sentry Logger [log]: Flushing events before Vercel Lambda freeze',
+        'Sentry Logger [log]: SpanExporter exported 4 spans, 0 spans are waiting for their parent spans to finish',
+      ];
+
+      // Test that the order of logs is correct
+      for (const log of actualLogs) {
+        if (expectedLogs.length === 0) {
+          break;
+        }
+
+        if (log === expectedLogs[0]) {
+          expectedLogs.shift();
+        }
+      }
+
+      expect(expectedLogs).toEqual([]);
+    });
+  });
+});

packages/node/src/integrations/http/SentryHttpInstrumentationBeforeOtel.ts

@@ -68,8 +68,7 @@ export class SentryHttpInstrumentationBeforeOtel extends InstrumentationBase {
           return original.apply(this, args);
         }
 
-        const response = args[1] as http.OutgoingMessage;
-
+        const response = args[2] as http.OutgoingMessage;
         patchResponseToFlushOnServerlessPlatforms(response);
 
         return original.apply(this, args);
@@ -81,50 +80,57 @@ export class SentryHttpInstrumentationBeforeOtel extends InstrumentationBase {
 function patchResponseToFlushOnServerlessPlatforms(res: http.OutgoingMessage): void {
   // Freely extend this function with other platforms if necessary
   if (process.env.VERCEL) {
+    DEBUG_BUILD && logger.log('Patching response to flush on Vercel');
+
     // In some cases res.end does not seem to be defined leading to errors if passed to Proxy
     // https://github.com/getsentry/sentry-javascript/issues/15759
-    if (typeof res.end === 'function') {
-      let markOnEndDone = (): void => undefined;
-      const onEndDonePromise = new Promise<void>(res => {
-        markOnEndDone = res;
-      });
-
-      res.on('close', () => {
-        markOnEndDone();
-      });
-
-      // eslint-disable-next-line @typescript-eslint/unbound-method
-      res.end = new Proxy(res.end, {
-        apply(target, thisArg, argArray) {
-          vercelWaitUntil(
-            new Promise<void>(finishWaitUntil => {
-              // Define a timeout that unblocks the lambda just to be safe so we're not indefinitely keeping it alive, exploding server bills
-              const timeout = setTimeout(() => {
-                finishWaitUntil();
-              }, 2000);
-
-              onEndDonePromise
-                .then(() => {
-                  DEBUG_BUILD && logger.log('Flushing events before Vercel Lambda freeze');
-                  return flush(2000);
-                })
-                .then(
-                  () => {
-                    clearTimeout(timeout);
-                    finishWaitUntil();
-                  },
-                  e => {
-                    clearTimeout(timeout);
-                    DEBUG_BUILD && logger.log('Error while flushing events for Vercel:\n', e);
-                    finishWaitUntil();
-                  },
-                );
-            }),
-          );
-
-          return target.apply(thisArg, argArray);
-        },
-      });
+    if (typeof res.end !== 'function') {
+      DEBUG_BUILD && logger.warn('res.end is not a function, skipping patch...');
+      return;
     }
+
+    let markOnEndDone = (): void => undefined;
+    const onEndDonePromise = new Promise<void>(res => {
+      markOnEndDone = res;
+    });
+
+    res.on('close', () => {
+      markOnEndDone();
+    });
+
+    logger.log('Patching res.end()');
+
+    // eslint-disable-next-line @typescript-eslint/unbound-method
+    res.end = new Proxy(res.end, {
+      apply(target, thisArg, argArray) {
+        vercelWaitUntil(
+          new Promise<void>(finishWaitUntil => {
+            // Define a timeout that unblocks the lambda just to be safe so we're not indefinitely keeping it alive, exploding server bills
+            const timeout = setTimeout(() => {
+              finishWaitUntil();
+            }, 2000);
+
+            onEndDonePromise
+              .then(() => {
+                DEBUG_BUILD && logger.log('Flushing events before Vercel Lambda freeze');
+                return flush(2000);
+              })
+              .then(
+                () => {
+                  clearTimeout(timeout);
+                  finishWaitUntil();
+                },
+                e => {
+                  clearTimeout(timeout);
+                  DEBUG_BUILD && logger.log('Error while flushing events for Vercel:\n', e);
+                  finishWaitUntil();
+                },
+              );
+          }),
+        );
+
+        return target.apply(thisArg, argArray);
+      },
+    });
   }
 }