Skip to content

feat(tracing): Add long task collection #5529

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 24 commits into from
Aug 12, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
24 commits
Select commit Hold shift + click to select a range
a7995eb
rfc(perf): Add long task collection
k-fish Aug 5, 2022
1df4bf1
Cleanup and add a playwright test
k-fish Aug 5, 2022
a0dd40d
Check for active transactions as long tasks occur, not ahead
k-fish Aug 5, 2022
ce4ad87
Prettier fix
k-fish Aug 5, 2022
5a73d4d
Fix test
k-fish Aug 5, 2022
5bebba4
Fix timestamp names in test
k-fish Aug 5, 2022
f662902
Fix names... again
k-fish Aug 5, 2022
6206e04
Remove consoles from test suite mock script
k-fish Aug 8, 2022
7a7ae98
Merge remote-tracking branch 'origin/master' into ref/add-long-task-c…
k-fish Aug 8, 2022
53dc48d
Add span for long task in the transaction
k-fish Aug 9, 2022
fe9144a
Merge remote-tracking branch 'origin/master' into ref/add-long-task-c…
k-fish Aug 9, 2022
54664a2
Remove extra span since it's likely just flaky, not a long task
k-fish Aug 10, 2022
0b2c253
Temporarily improve error message to understand reason for test failure
k-fish Aug 10, 2022
e9a9d9e
Rearrange transaction count check
k-fish Aug 10, 2022
7eef4a5
Fix newer syntax
k-fish Aug 10, 2022
923dd66
See if removing the long task detection causes next tests to pass
k-fish Aug 10, 2022
ec58516
Also remove import
k-fish Aug 10, 2022
abf11dc
Wrap in try catch incase there is an internal error
k-fish Aug 10, 2022
be21d5d
Try again without try and extra logging since local is working
k-fish Aug 11, 2022
8ae755c
Add origin to start time to stop flaking long tasks from appearing at…
k-fish Aug 11, 2022
b821c0f
Fix array contains needing exact matches for spans in transaction mat…
k-fish Aug 11, 2022
5aa7b75
Add experiment flag as a way of disabling this feature, which can be …
k-fish Aug 11, 2022
63a171c
Fix tests
k-fish Aug 12, 2022
d747811
Don't want to wait for eslint fix
k-fish Aug 12, 2022
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
(() => {
const startTime = Date.now();

function getElasped() {
const time = Date.now();
return time - startTime;
}

while (getElasped() < 101) {
//
}
})();
Original file line number Diff line number Diff line change
@@ -0,0 +1,10 @@
import * as Sentry from '@sentry/browser';
import { Integrations } from '@sentry/tracing';

window.Sentry = Sentry;

Sentry.init({
dsn: 'https://[email protected]/1337',
integrations: [new Integrations.BrowserTracing({ _experiments: { enableLongTasks: false }, idleTimeout: 9000 })],
tracesSampleRate: 1,
});
Original file line number Diff line number Diff line change
@@ -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>
Original file line number Diff line number Diff line change
@@ -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);
});
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
(() => {
const startTime = Date.now();

function getElasped() {
const time = Date.now();
return time - startTime;
}

while (getElasped() < 105) {
//
}
})();
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
import * as Sentry from '@sentry/browser';
import { Integrations } from '@sentry/tracing';

window.Sentry = Sentry;

Sentry.init({
dsn: 'https://[email protected]/1337',
integrations: [
new Integrations.BrowserTracing({
idleTimeout: 9000,
}),
],
tracesSampleRate: 1,
});
Original file line number Diff line number Diff line change
@@ -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>
Original file line number Diff line number Diff line change
@@ -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);
});
8 changes: 6 additions & 2 deletions packages/nextjs/test/integration/test/client/tracingFetch.js
Original file line number Diff line number Diff line change
@@ -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`);
Expand All @@ -21,6 +26,5 @@ module.exports = async ({ page, url, requests }) => {
},
],
});

await expectRequestCount(requests, { transactions: 1 });
};
5 changes: 4 additions & 1 deletion packages/nextjs/test/integration/test/utils/client.js
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
const { strictEqual } = require('assert');
const expect = require('expect');
const { logIf, parseEnvelope } = require('./common');

const VALID_REQUEST_PAYLOAD = {
Expand Down Expand Up @@ -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);
}
Expand Down
14 changes: 13 additions & 1 deletion packages/tracing/src/browser/browsertracing.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand All @@ -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,
Expand Down Expand Up @@ -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).
Expand Down Expand Up @@ -101,6 +109,7 @@ const DEFAULT_BROWSER_TRACING_OPTIONS = {
routingInstrumentation: instrumentRoutingWithDefaults,
startTransactionOnLocationChange: true,
startTransactionOnPageLoad: true,
_experiments: { enableLongTask: true },
...defaultRequestInstrumentationOptions,
};

Expand Down Expand Up @@ -148,6 +157,9 @@ export class BrowserTracing implements Integration {

const { _metricOptions } = this.options;
startTrackingWebVitals(_metricOptions && _metricOptions._reportAllChanges);
if (this.options._experiments?.enableLongTask) {
startTrackingLongTasks();
}
}

/**
Expand Down
26 changes: 25 additions & 1 deletion packages/tracing/src/browser/metrics/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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';

Expand Down Expand Up @@ -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:
Expand Down
3 changes: 3 additions & 0 deletions packages/tracing/test/browser/browsertracing.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down