fix(core): Rethrow caught promise rejections in startSpan, startSpanManual, trace (#9958)

Lms24 · web-flow · commit cf412d937396 · 2023-12-22T11:23:49.000+01:00
Our previous implementation of `startSpan` et.al. assumed
that because we were "cloning" the original promise, unhandled promise
rejections would still bubble up to the global `onunhandledrejection`
handler so that Sentry would catch the error.

However, we tried investigating this and found out that our "cloning"
mechanism didn't work correctly and because we already added a rejection
handler, the promise rejection would _not always_ make it to the global
handler.

After adding multiple integration tests, I further narrowed the buggy
behaviour down to a rather special case: The `startSpan` call is not `await`ed
which for some reason will lead to the SDK not catching the error.
Unless, we apply the fix in this PR.

This patch removes this cloning mechanism in favour of directly attaching a
rejection handler to the promise. In this handler, we rethrow the error
which should trigger the global handlers.
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/basic/subject.js b/packages/browser-integration-tests/suites/public-api/startSpan/basic/subject.js
@@ -0,0 +1,9 @@
+async function run() {
+  Sentry.startSpan({ name: 'parent_span' }, () => {
+    Sentry.startSpan({ name: 'child_span' }, () => {
+      // whatever a user would do here
+    });
+  });
+}
+
+run();
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/basic/test.ts b/packages/browser-integration-tests/suites/public-api/startSpan/basic/test.ts
@@ -0,0 +1,34 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getFirstSentryEnvelopeRequest, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+sentryTest('should send a transaction in an envelope', async ({ getLocalTestPath, page }) => {
+  if (shouldSkipTracingTest()) {
+    sentryTest.skip();
+  }
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+  const transaction = await getFirstSentryEnvelopeRequest<Event>(page, url);
+
+  expect(transaction.transaction).toBe('parent_span');
+  expect(transaction.spans).toBeDefined();
+});
+
+sentryTest('should report finished spans as children of the root transaction', async ({ getLocalTestPath, page }) => {
+  if (shouldSkipTracingTest()) {
+    sentryTest.skip();
+  }
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+  const transaction = await getFirstSentryEnvelopeRequest<Event>(page, url);
+
+  const rootSpanId = transaction?.contexts?.trace?.spanId;
+
+  expect(transaction.spans).toHaveLength(1);
+
+  const span_1 = transaction.spans?.[0];
+  expect(span_1?.description).toBe('child_span');
+  expect(span_1?.parentSpanId).toEqual(rootSpanId);
+});
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-reject/template.html b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-reject/template.html
@@ -0,0 +1,23 @@
+<!DOCTYPE html>
+<html>
+  <head>
+    <meta charset="utf-8" />
+    <title></title>
+  </head>
+  <body>
+    <button id="button1" type="button">Button 1</button>
+
+    <script>
+      async function run() {
+        await Sentry.startSpan({ name: 'parent_span', op: 'test' }, async () => {
+          Promise.reject('Async Promise Rejection');
+        });
+      }
+
+      const button = document.getElementById('button1');
+      button.addEventListener('click', async () => {
+        await run();
+      });
+    </script>
+  </body>
+</html>
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-reject/test.ts b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-reject/test.ts
@@ -0,0 +1,31 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getMultipleSentryEnvelopeRequests, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+sentryTest(
+  'should capture a promise rejection within an async startSpan callback',
+  async ({ getLocalTestPath, page }) => {
+    if (shouldSkipTracingTest()) {
+      sentryTest.skip();
+    }
+
+    const url = await getLocalTestPath({ testDir: __dirname });
+    const envelopePromise = getMultipleSentryEnvelopeRequests<Event>(page, 2);
+
+    await page.goto(url);
+
+    const clickPromise = page.getByText('Button 1').click();
+
+    const [, events] = await Promise.all([clickPromise, envelopePromise]);
+    const txn = events.find(event => event.type === 'transaction');
+    const err = events.find(event => !event.type);
+
+    expect(txn).toMatchObject({ transaction: 'parent_span' });
+
+    expect(err?.exception?.values?.[0]?.value).toBe(
+      'Non-Error promise rejection captured with value: Async Promise Rejection',
+    );
+  },
+);
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw-not-awaited/template.html b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw-not-awaited/template.html
@@ -0,0 +1,23 @@
+<!DOCTYPE html>
+<html>
+  <head>
+    <meta charset="utf-8" />
+    <title></title>
+  </head>
+  <body>
+    <button id="button1" type="button">Button 1</button>
+
+    <script type="module">
+      async function run() {
+        Sentry.startSpan({ name: 'parent_span', op: 'test' }, async () => {
+          throw new Error('Async Thrown Error');
+        });
+      }
+
+      const button = document.getElementById('button1');
+      button.addEventListener('click', () => {
+        void run();
+      });
+    </script>
+  </body>
+</html>
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw-not-awaited/test.ts b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw-not-awaited/test.ts
@@ -0,0 +1,28 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getMultipleSentryEnvelopeRequests, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+sentryTest(
+  "should capture a thrown error within an async startSpan callback that's not awaited properly",
+  async ({ getLocalTestPath, page }) => {
+    if (shouldSkipTracingTest()) {
+      sentryTest.skip();
+    }
+    const envelopePromise = getMultipleSentryEnvelopeRequests<Event>(page, 2);
+
+    const url = await getLocalTestPath({ testDir: __dirname });
+    await page.goto(url);
+
+    const clickPromise = page.getByText('Button 1').click();
+
+    // awaiting both events simultaneously to avoid race conditions
+    const [, events] = await Promise.all([clickPromise, envelopePromise]);
+    const txn = events.find(event => event.type === 'transaction');
+    const err = events.find(event => !event.type);
+
+    expect(txn).toMatchObject({ transaction: 'parent_span' });
+    expect(err?.exception?.values?.[0]?.value).toBe('Async Thrown Error');
+  },
+);
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw/template.html b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw/template.html
@@ -0,0 +1,24 @@
+<!DOCTYPE html>
+<html>
+  <head>
+    <meta charset="utf-8" />
+    <title></title>
+  </head>
+  <body>
+    <button id="button1" type="button">Button 1</button>
+
+    <script type="module">
+      async function run() {
+        await Promise.resolve();
+        await Sentry.startSpan({ name: 'parent_span', op: 'test' }, async () => {
+          throw new Error('Async Thrown Error');
+        });
+      }
+
+      const button = document.getElementById('button1');
+      button.addEventListener('click', () => {
+        void run();
+      });
+    </script>
+  </body>
+</html>
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw/test.ts b/packages/browser-integration-tests/suites/public-api/startSpan/error-async-throw/test.ts
@@ -0,0 +1,25 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getMultipleSentryEnvelopeRequests, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+sentryTest('should capture a thrown error within an async startSpan callback', async ({ getLocalTestPath, page }) => {
+  if (shouldSkipTracingTest()) {
+    sentryTest.skip();
+  }
+  const envelopePromise = getMultipleSentryEnvelopeRequests<Event>(page, 2);
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+  await page.goto(url);
+
+  const clickPromise = page.getByText('Button 1').click();
+
+  // awaiting both events simultaneously to avoid race conditions
+  const [, events] = await Promise.all([clickPromise, envelopePromise]);
+  const txn = events.find(event => event.type === 'transaction');
+  const err = events.find(event => !event.type);
+
+  expect(txn).toMatchObject({ transaction: 'parent_span' });
+  expect(err?.exception?.values?.[0]?.value).toBe('Async Thrown Error');
+});
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-sync/subject.js b/packages/browser-integration-tests/suites/public-api/startSpan/error-sync/subject.js
@@ -0,0 +1,9 @@
+function run() {
+  Sentry.startSpan({ name: 'parent_span' }, () => {
+    throw new Error('Sync Error');
+  });
+}
+
+// using `setTimeout` here because otherwise the thrown error will be
+// thrown as a generic "Script Error." instead of the actual error".
+setTimeout(run);
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/error-sync/test.ts b/packages/browser-integration-tests/suites/public-api/startSpan/error-sync/test.ts
@@ -0,0 +1,22 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getMultipleSentryEnvelopeRequests, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+sentryTest('should capture an error within a sync startSpan callback', async ({ getLocalTestPath, page }) => {
+  if (shouldSkipTracingTest()) {
+    sentryTest.skip();
+  }
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+  const gotoPromise = page.goto(url);
+  const envelopePromise = getMultipleSentryEnvelopeRequests<Event>(page, 2);
+
+  const [_, events] = await Promise.all([gotoPromise, envelopePromise]);
+  const txn = events.find(event => event.type === 'transaction');
+  const err = events.find(event => !event.type);
+
+  expect(txn).toMatchObject({ transaction: 'parent_span' });
+  expect(err?.exception?.values?.[0]?.value).toBe('Sync Error');
+});
diff --git a/packages/browser-integration-tests/suites/public-api/startSpan/init.js b/packages/browser-integration-tests/suites/public-api/startSpan/init.js
@@ -0,0 +1,13 @@
+/* eslint-disable no-unused-vars */
+import * as Sentry from '@sentry/browser';
+// biome-ignore lint/nursery/noUnusedImports: Need to import tracing for side effect
+import * as _ from '@sentry/tracing';
+
+window.Sentry = Sentry;
+
+Sentry.init({
+  dsn: 'https://public@dsn.ingest.sentry.io/1337',
+  tracesSampleRate: 1.0,
+  normalizeDepth: 10,
+  debug: true,
+});
diff --git a/packages/core/src/tracing/trace.ts b/packages/core/src/tracing/trace.ts
@@ -55,23 +55,25 @@ export function trace<T>(
   }
 
   if (isThenable(maybePromiseResult)) {
-    Promise.resolve(maybePromiseResult).then(
-      () => {
+    // @ts-expect-error - the isThenable check returns the "wrong" type here
+    return maybePromiseResult.then(
+      res => {
         finishAndSetSpan();
         afterFinish();
+        return res;
       },
       e => {
         activeSpan && activeSpan.setStatus('internal_error');
         onError(e, activeSpan);
         finishAndSetSpan();
         afterFinish();
+        throw e;
       },
     );
-  } else {
-    finishAndSetSpan();
-    afterFinish();
   }
 
+  finishAndSetSpan();
+  afterFinish();
   return maybePromiseResult;
 }
 
@@ -89,6 +91,7 @@ export function trace<T>(
 export function startSpan<T>(context: TransactionContext, callback: (span: Span | undefined) => T): T {
   const ctx = normalizeContext(context);
 
+  // @ts-expect-error - isThenable returns the wrong type
   return withScope(scope => {
     const hub = getCurrentHub();
     const parentSpan = scope.getSpan();
@@ -110,19 +113,20 @@ export function startSpan<T>(context: TransactionContext, callback: (span: Span
     }
 
     if (isThenable(maybePromiseResult)) {
-      Promise.resolve(maybePromiseResult).then(
-        () => {
+      return maybePromiseResult.then(
+        res => {
           finishAndSetSpan();
+          return res;
         },
-        () => {
+        e => {
           activeSpan && activeSpan.setStatus('internal_error');
           finishAndSetSpan();
+          throw e;
         },
       );
-    } else {
-      finishAndSetSpan();
     }
 
+    finishAndSetSpan();
     return maybePromiseResult;
   });
 }
@@ -149,6 +153,7 @@ export function startSpanManual<T>(
 ): T {
   const ctx = normalizeContext(context);
 
+  // @ts-expect-error - isThenable returns the wrong type
   return withScope(scope => {
     const hub = getCurrentHub();
     const parentSpan = scope.getSpan();
@@ -169,9 +174,13 @@ export function startSpanManual<T>(
     }
 
     if (isThenable(maybePromiseResult)) {
-      Promise.resolve(maybePromiseResult).then(undefined, () => {
-        activeSpan && activeSpan.setStatus('internal_error');
-      });
+      return maybePromiseResult.then(
+        res => res,
+        e => {
+          activeSpan && activeSpan.setStatus('internal_error');
+          throw e;
+        },
+      );
     }
 
     return maybePromiseResult;
