feat(tracing): Add long task collection (#5529)

k-fish · web-flow · commit dbd83406dcdd · 2022-08-12T13:59:11.000-04:00
* rfc(perf): Add long task collection

This adds long task collection to represent long running ui behaviour as spans in your frontend transactions. Can be disabled by passing an experimental flag for now.
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/assets/script.js b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/assets/script.js
@@ -0,0 +1,12 @@
+(() => {
+  const startTime = Date.now();
+
+  function getElasped() {
+    const time = Date.now();
+    return time - startTime;
+  }
+
+  while (getElasped() < 101) {
+    //
+  }
+})();
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/init.js b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/init.js
@@ -0,0 +1,10 @@
+import * as Sentry from '@sentry/browser';
+import { Integrations } from '@sentry/tracing';
+
+window.Sentry = Sentry;
+
+Sentry.init({
+  dsn: 'https://public@dsn.ingest.sentry.io/1337',
+  integrations: [new Integrations.BrowserTracing({ _experiments: { enableLongTasks: false }, idleTimeout: 9000 })],
+  tracesSampleRate: 1,
+});
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/template.html b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/template.html
@@ -0,0 +1,9 @@
+<html>
+  <head>
+    <meta charset="utf-8" />
+  </head>
+  <body>
+    <div>Rendered Before Long Task</div>
+    <script src="https://example.com/path/to/script.js"></script>
+  </body>
+</html>
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/test.ts b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-disabled/test.ts
@@ -0,0 +1,21 @@
+import { expect, Route } from '@playwright/test';
+import { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getFirstSentryEnvelopeRequest } from '../../../../utils/helpers';
+
+sentryTest('should not capture long task when flag is disabled.', async ({ browserName, getLocalTestPath, page }) => {
+  // Long tasks only work on chrome
+  if (browserName !== 'chromium') {
+    sentryTest.skip();
+  }
+
+  await page.route('**/path/to/script.js', (route: Route) => route.fulfill({ path: `${__dirname}/assets/script.js` }));
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+
+  const eventData = await getFirstSentryEnvelopeRequest<Event>(page, url);
+  const uiSpans = eventData.spans?.filter(({ op }) => op?.startsWith('ui'));
+
+  expect(uiSpans?.length).toBe(0);
+});
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/assets/script.js b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/assets/script.js
@@ -0,0 +1,12 @@
+(() => {
+  const startTime = Date.now();
+
+  function getElasped() {
+    const time = Date.now();
+    return time - startTime;
+  }
+
+  while (getElasped() < 105) {
+    //
+  }
+})();
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/init.js b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/init.js
@@ -0,0 +1,14 @@
+import * as Sentry from '@sentry/browser';
+import { Integrations } from '@sentry/tracing';
+
+window.Sentry = Sentry;
+
+Sentry.init({
+  dsn: 'https://public@dsn.ingest.sentry.io/1337',
+  integrations: [
+    new Integrations.BrowserTracing({
+      idleTimeout: 9000,
+    }),
+  ],
+  tracesSampleRate: 1,
+});
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/template.html b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/template.html
@@ -0,0 +1,9 @@
+<html>
+  <head>
+    <meta charset="utf-8" />
+  </head>
+  <body>
+    <div>Rendered Before Long Task</div>
+    <script src="https://example.com/path/to/script.js"></script>
+  </body>
+</html>
diff --git a/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/test.ts b/packages/integration-tests/suites/tracing/browsertracing/long-tasks-enabled/test.ts
@@ -0,0 +1,36 @@
+import { expect, Route } from '@playwright/test';
+import { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getFirstSentryEnvelopeRequest } from '../../../../utils/helpers';
+
+sentryTest('should capture long task.', async ({ browserName, getLocalTestPath, page }) => {
+  // Long tasks only work on chrome
+  if (browserName !== 'chromium') {
+    sentryTest.skip();
+  }
+
+  await page.route('**/path/to/script.js', (route: Route) => route.fulfill({ path: `${__dirname}/assets/script.js` }));
+
+  const url = await getLocalTestPath({ testDir: __dirname });
+
+  const eventData = await getFirstSentryEnvelopeRequest<Event>(page, url);
+  const uiSpans = eventData.spans?.filter(({ op }) => op?.startsWith('ui'));
+
+  expect(uiSpans?.length).toBe(1);
+
+  const [firstUISpan] = uiSpans || [];
+  expect(firstUISpan).toEqual(
+    expect.objectContaining({
+      op: 'ui.long-task',
+      description: 'Long Task',
+      parent_span_id: eventData.contexts?.trace.span_id,
+    }),
+  );
+  const start = firstUISpan['start_timestamp'] ?? 0;
+  const end = firstUISpan['timestamp'] ?? 0;
+  const duration = end - start;
+
+  expect(duration).toBeGreaterThanOrEqual(0.1);
+  expect(duration).toBeLessThanOrEqual(0.15);
+});
diff --git a/packages/nextjs/test/integration/test/client/tracingFetch.js b/packages/nextjs/test/integration/test/client/tracingFetch.js
@@ -1,4 +1,9 @@
-const { expectRequestCount, isTransactionRequest, expectTransaction } = require('../utils/client');
+const {
+  expectRequestCount,
+  isTransactionRequest,
+  expectTransaction,
+  extractEnvelopeFromRequest,
+} = require('../utils/client');
 
 module.exports = async ({ page, url, requests }) => {
   await page.goto(`${url}/fetch`);
@@ -21,6 +26,5 @@ module.exports = async ({ page, url, requests }) => {
       },
     ],
   });
-
   await expectRequestCount(requests, { transactions: 1 });
 };
diff --git a/packages/nextjs/test/integration/test/utils/client.js b/packages/nextjs/test/integration/test/utils/client.js
@@ -1,4 +1,5 @@
 const { strictEqual } = require('assert');
+const expect = require('expect');
 const { logIf, parseEnvelope } = require('./common');
 
 const VALID_REQUEST_PAYLOAD = {
@@ -105,8 +106,10 @@ const assertObjectMatches = (actual, expected) => {
   for (const key in expected) {
     const expectedValue = expected[key];
 
-    if (Object.prototype.toString.call(expectedValue) === '[object Object]' || Array.isArray(expectedValue)) {
+    if (Object.prototype.toString.call(expectedValue) === '[object Object]') {
       assertObjectMatches(actual[key], expectedValue);
+    } else if (Array.isArray(expectedValue)) {
+      expect(actual[key]).toEqual(expect.arrayContaining(expectedValue.map(expect.objectContaining)));
     } else {
       strictEqual(actual[key], expectedValue);
     }
diff --git a/packages/tracing/src/browser/browsertracing.ts b/packages/tracing/src/browser/browsertracing.ts
@@ -1,3 +1,4 @@
+/* eslint-disable max-lines */
 import { Hub } from '@sentry/hub';
 import { EventProcessor, Integration, Transaction, TransactionContext } from '@sentry/types';
 import { getGlobalObject, logger, parseBaggageSetMutability } from '@sentry/utils';
@@ -6,7 +7,7 @@ import { startIdleTransaction } from '../hubextensions';
 import { DEFAULT_FINAL_TIMEOUT, DEFAULT_IDLE_TIMEOUT } from '../idletransaction';
 import { extractTraceparentData } from '../utils';
 import { registerBackgroundTabDetection } from './backgroundtab';
-import { addPerformanceEntries, startTrackingWebVitals } from './metrics';
+import { addPerformanceEntries, startTrackingLongTasks, startTrackingWebVitals } from './metrics';
 import {
   defaultRequestInstrumentationOptions,
   instrumentOutgoingRequests,
@@ -71,6 +72,13 @@ export interface BrowserTracingOptions extends RequestInstrumentationOptions {
    */
   _metricOptions?: Partial<{ _reportAllChanges: boolean }>;
 
+  /**
+   * _experiments allows the user to send options to define how this integration works.
+   *
+   * Default: undefined
+   */
+  _experiments?: Partial<{ enableLongTask: boolean }>;
+
   /**
    * beforeNavigate is called before a pageload/navigation transaction is created and allows users to modify transaction
    * context data, or drop the transaction entirely (by setting `sampled = false` in the context).
@@ -101,6 +109,7 @@ const DEFAULT_BROWSER_TRACING_OPTIONS = {
   routingInstrumentation: instrumentRoutingWithDefaults,
   startTransactionOnLocationChange: true,
   startTransactionOnPageLoad: true,
+  _experiments: { enableLongTask: true },
   ...defaultRequestInstrumentationOptions,
 };
 
@@ -148,6 +157,9 @@ export class BrowserTracing implements Integration {
 
     const { _metricOptions } = this.options;
     startTrackingWebVitals(_metricOptions && _metricOptions._reportAllChanges);
+    if (this.options._experiments?.enableLongTask) {
+      startTrackingLongTasks();
+    }
   }
 
   /**
diff --git a/packages/tracing/src/browser/metrics/index.ts b/packages/tracing/src/browser/metrics/index.ts
@@ -2,12 +2,14 @@
 import { Measurements } from '@sentry/types';
 import { browserPerformanceTimeOrigin, getGlobalObject, htmlTreeAsString, logger } from '@sentry/utils';
 
+import { IdleTransaction } from '../../idletransaction';
 import { Transaction } from '../../transaction';
-import { msToSec } from '../../utils';
+import { getActiveTransaction, msToSec } from '../../utils';
 import { getCLS, LayoutShift } from '../web-vitals/getCLS';
 import { getFID } from '../web-vitals/getFID';
 import { getLCP, LargestContentfulPaint } from '../web-vitals/getLCP';
 import { getVisibilityWatcher } from '../web-vitals/lib/getVisibilityWatcher';
+import { observe, PerformanceEntryHandler } from '../web-vitals/lib/observe';
 import { NavigatorDeviceMemory, NavigatorNetworkInformation } from '../web-vitals/types';
 import { _startChild, isMeasurementValue } from './utils';
 
@@ -38,6 +40,28 @@ export function startTrackingWebVitals(reportAllChanges: boolean = false): void
   }
 }
 
+/**
+ * Start tracking long tasks.
+ */
+export function startTrackingLongTasks(): void {
+  const entryHandler: PerformanceEntryHandler = (entry: PerformanceEntry): void => {
+    const transaction = getActiveTransaction() as IdleTransaction | undefined;
+    if (!transaction) {
+      return;
+    }
+    const startTime = msToSec((browserPerformanceTimeOrigin as number) + entry.startTime);
+    const duration = msToSec(entry.duration);
+    transaction.startChild({
+      description: 'Long Task',
+      op: 'ui.long-task',
+      startTimestamp: startTime,
+      endTimestamp: startTime + duration,
+    });
+  };
+
+  observe('longtask', entryHandler);
+}
+
 /** Starts tracking the Cumulative Layout Shift on the current page. */
 function _trackCLS(): void {
   // See:
diff --git a/packages/tracing/test/browser/browsertracing.test.ts b/packages/tracing/test/browser/browsertracing.test.ts
@@ -89,6 +89,9 @@ describe('BrowserTracing', () => {
     const browserTracing = createBrowserTracing();
 
     expect(browserTracing.options).toEqual({
+      _experiments: {
+        enableLongTask: true,
+      },
       idleTimeout: DEFAULT_IDLE_TIMEOUT,
       finalTimeout: DEFAULT_FINAL_TIMEOUT,
       markBackgroundTransactions: true,
