Skip to content

feat(metrics): Add timings method to metrics #12226

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 6 commits into from
May 28, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Expand Up @@ -15,3 +15,20 @@ Sentry.metrics.gauge('gauge', 5);
Sentry.metrics.gauge('gauge', '15');
Sentry.metrics.set('set', 'nope');
Sentry.metrics.set('set', 'another');

Sentry.metrics.timing('timing', 99, 'hour');
Sentry.metrics.timing('timingSync', () => {
sleepSync(200);
});
Sentry.metrics.timing('timingAsync', async () => {
await new Promise(resolve => setTimeout(resolve, 200));
});

function sleepSync(milliseconds) {
var start = new Date().getTime();
for (var i = 0; i < 1e7; i++) {
if (new Date().getTime() - start > milliseconds) {
break;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -17,9 +17,18 @@ sentryTest('collects metrics', async ({ getLocalTestUrl, page }) => {
const statsdBuffer = await getFirstSentryEnvelopeRequest<Uint8Array>(page, url, properEnvelopeRequestParser);
const statsdString = new TextDecoder().decode(statsdBuffer);
// Replace all the Txxxxxx to remove the timestamps
const normalisedStatsdString = statsdString.replace(/T\d+\n?/g, 'T000000');
const normalisedStatsdString = statsdString.replace(/T\d+\n?/g, 'T000000').trim();

expect(normalisedStatsdString).toEqual(
'increment@none:6|c|T000000distribution@none:42:45|d|T000000gauge@none:15:5:15:20:2|g|T000000set@none:3387254:3443787523|s|T000000',
);
const parts = normalisedStatsdString.split('T000000');

expect(parts).toEqual([
'increment@none:6|c|',
'distribution@none:42:45|d|',
'gauge@none:15:5:15:20:2|g|',
'set@none:3387254:3443787523|s|',
'timing@hour:99|d|',
expect.stringMatching(/timingSync@second:0.(\d+)\|d\|/),
expect.stringMatching(/timingAsync@second:0.(\d+)\|d\|/),
'', // trailing element
]);
});
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
import * as Sentry from '@sentry/browser';

window.Sentry = Sentry;

Sentry.init({
dsn: 'https://[email protected]/1337',
tracesSampleRate: 1.0,
release: '1.0.0',
autoSessionTracking: false,
});

window.timingSync = () => {
// Ensure we always have a wrapping span
return Sentry.startSpan({ name: 'manual span' }, () => {
return Sentry.metrics.timing('timingSync', () => {
sleepSync(200);
return 'sync done';
});
});
};

window.timingAsync = () => {
// Ensure we always have a wrapping span
return Sentry.startSpan({ name: 'manual span' }, () => {
return Sentry.metrics.timing('timingAsync', async () => {
await new Promise(resolve => setTimeout(resolve, 200));
return 'async done';
});
});
};

function sleepSync(milliseconds) {
var start = new Date().getTime();
for (var i = 0; i < 1e7; i++) {
if (new Date().getTime() - start > milliseconds) {
break;
}
}
}
175 changes: 175 additions & 0 deletions dev-packages/browser-integration-tests/suites/metrics/timing/test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,175 @@
import { expect } from '@playwright/test';

import { sentryTest } from '../../../utils/fixtures';
import {
envelopeRequestParser,
properEnvelopeRequestParser,
shouldSkipTracingTest,
waitForTransactionRequest,
} from '../../../utils/helpers';

sentryTest('allows to wrap sync methods with a timing metric', async ({ getLocalTestUrl, page }) => {
if (shouldSkipTracingTest()) {
sentryTest.skip();
}

await page.route('https://dsn.ingest.sentry.io/**/*', route => {
return route.fulfill({
status: 200,
contentType: 'application/json',
body: JSON.stringify({ id: 'test-id' }),
});
});

const url = await getLocalTestUrl({ testDir: __dirname });

const beforeTime = Math.floor(Date.now() / 1000);

const metricsPromiseReq = page.waitForRequest(req => {
const postData = req.postData();
if (!postData) {
return false;
}

try {
// this implies this is a metrics envelope
return typeof envelopeRequestParser(req) === 'string';
} catch {
return false;
}
});

const transactionPromise = waitForTransactionRequest(page);

await page.goto(url);
await page.waitForFunction('typeof window.timingSync === "function"');
const response = await page.evaluate('window.timingSync()');

expect(response).toBe('sync done');

const statsdString = envelopeRequestParser<string>(await metricsPromiseReq);
const transactionEvent = properEnvelopeRequestParser(await transactionPromise);

expect(typeof statsdString).toEqual('string');

const parsedStatsd = /timingSync@second:(0\.\d+)\|d\|#(.+)\|T(\d+)/.exec(statsdString);

expect(parsedStatsd).toBeTruthy();

const duration = parseFloat(parsedStatsd![1]);
const tags = parsedStatsd![2];
const timestamp = parseInt(parsedStatsd![3], 10);

expect(timestamp).toBeGreaterThanOrEqual(beforeTime);
expect(tags).toEqual('release:1.0.0,transaction:manual span');
expect(duration).toBeGreaterThan(0.2);
expect(duration).toBeLessThan(1);

expect(transactionEvent).toBeDefined();
expect(transactionEvent.transaction).toEqual('manual span');

const spans = transactionEvent.spans || [];

expect(spans.length).toBe(1);
const span = spans[0];
expect(span.op).toEqual('metrics.timing');
expect(span.description).toEqual('timingSync');
expect(span.timestamp! - span.start_timestamp).toEqual(duration);
expect(span._metrics_summary).toEqual({
'd:timingSync@second': [
{
count: 1,
max: duration,
min: duration,
sum: duration,
tags: {
release: '1.0.0',
transaction: 'manual span',
},
},
],
});
});

sentryTest('allows to wrap async methods with a timing metric', async ({ getLocalTestUrl, page }) => {
if (shouldSkipTracingTest()) {
sentryTest.skip();
}

await page.route('https://dsn.ingest.sentry.io/**/*', route => {
return route.fulfill({
status: 200,
contentType: 'application/json',
body: JSON.stringify({ id: 'test-id' }),
});
});

const url = await getLocalTestUrl({ testDir: __dirname });

const beforeTime = Math.floor(Date.now() / 1000);

const metricsPromiseReq = page.waitForRequest(req => {
const postData = req.postData();
if (!postData) {
return false;
}

try {
// this implies this is a metrics envelope
return typeof envelopeRequestParser(req) === 'string';
} catch {
return false;
}
});

const transactionPromise = waitForTransactionRequest(page);

await page.goto(url);
await page.waitForFunction('typeof window.timingAsync === "function"');
const response = await page.evaluate('window.timingAsync()');

expect(response).toBe('async done');

const statsdString = envelopeRequestParser<string>(await metricsPromiseReq);
const transactionEvent = properEnvelopeRequestParser(await transactionPromise);

expect(typeof statsdString).toEqual('string');

const parsedStatsd = /timingAsync@second:(0\.\d+)\|d\|#(.+)\|T(\d+)/.exec(statsdString);

expect(parsedStatsd).toBeTruthy();

const duration = parseFloat(parsedStatsd![1]);
const tags = parsedStatsd![2];
const timestamp = parseInt(parsedStatsd![3], 10);

expect(timestamp).toBeGreaterThanOrEqual(beforeTime);
expect(tags).toEqual('release:1.0.0,transaction:manual span');
expect(duration).toBeGreaterThan(0.2);
expect(duration).toBeLessThan(1);

expect(transactionEvent).toBeDefined();
expect(transactionEvent.transaction).toEqual('manual span');

const spans = transactionEvent.spans || [];

expect(spans.length).toBe(1);
const span = spans[0];
expect(span.op).toEqual('metrics.timing');
expect(span.description).toEqual('timingAsync');
expect(span.timestamp! - span.start_timestamp).toEqual(duration);
expect(span._metrics_summary).toEqual({
'd:timingAsync@second': [
{
count: 1,
max: duration,
min: duration,
sum: duration,
tags: {
release: '1.0.0',
transaction: 'manual span',
},
},
],
});
});
3 changes: 3 additions & 0 deletions dev-packages/rollup-utils/plugins/bundlePlugins.mjs
Original file line number Diff line number Diff line change
Expand Up @@ -121,7 +121,10 @@ export function makeTerserPlugin() {
// These are used by instrument.ts in utils for identifying HTML elements & events
'_sentryCaptured',
'_sentryId',
// Keeps the frozen DSC on a Sentry Span
'_frozenDsc',
// This keeps metrics summary on spans
'_metrics_summary',
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ooops turns out metrics summaries never worked for minified CDN bundles 😬 we had no tests covering this, now we have!

// These are used to keep span & scope relationships
'_sentryRootSpan',
'_sentryChildSpans',
Expand Down
23 changes: 22 additions & 1 deletion packages/browser/src/metrics.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import { BrowserMetricsAggregator, metrics as metricsCore } from '@sentry/core';
import type { MetricData, Metrics } from '@sentry/types';
import type { DurationUnit, MetricData, Metrics } from '@sentry/types';

/**
* Adds a value to a counter metric
Expand Down Expand Up @@ -37,9 +37,30 @@ function gauge(name: string, value: number, data?: MetricData): void {
metricsCore.gauge(BrowserMetricsAggregator, name, value, data);
}

/**
* Adds a timing metric.
* The metric is added as a distribution metric.
*
* You can either directly capture a numeric `value`, or wrap a callback function in `timing`.
* In the latter case, the duration of the callback execution will be captured as a span & a metric.
*
* @experimental This API is experimental and might have breaking changes in the future.
*/
function timing(name: string, value: number, unit?: DurationUnit, data?: Omit<MetricData, 'unit'>): void;
function timing<T>(name: string, callback: () => T, unit?: DurationUnit, data?: Omit<MetricData, 'unit'>): T;
function timing<T = void>(
name: string,
value: number | (() => T),
unit: DurationUnit = 'second',
data?: Omit<MetricData, 'unit'>,
): T | void {
return metricsCore.timing(BrowserMetricsAggregator, name, value, unit, data);
}

export const metrics: Metrics = {
increment,
distribution,
set,
gauge,
timing,
};
30 changes: 28 additions & 2 deletions packages/core/src/metrics/exports-default.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,10 @@
import type { Client, MetricData, Metrics, MetricsAggregator as MetricsAggregatorInterface } from '@sentry/types';
import type {
Client,
DurationUnit,
MetricData,
Metrics,
MetricsAggregator as MetricsAggregatorInterface,
} from '@sentry/types';
import { MetricsAggregator } from './aggregator';
import { metrics as metricsCore } from './exports';

Expand Down Expand Up @@ -38,6 +44,26 @@ function gauge(name: string, value: number, data?: MetricData): void {
metricsCore.gauge(MetricsAggregator, name, value, data);
}

/**
* Adds a timing metric.
* The metric is added as a distribution metric.
*
* You can either directly capture a numeric `value`, or wrap a callback function in `timing`.
* In the latter case, the duration of the callback execution will be captured as a span & a metric.
*
* @experimental This API is experimental and might have breaking changes in the future.
*/
function timing(name: string, value: number, unit?: DurationUnit, data?: Omit<MetricData, 'unit'>): void;
function timing<T>(name: string, callback: () => T, unit?: DurationUnit, data?: Omit<MetricData, 'unit'>): T;
function timing<T = void>(
name: string,
value: number | (() => T),
unit: DurationUnit = 'second',
data?: Omit<MetricData, 'unit'>,
): T | void {
return metricsCore.timing(MetricsAggregator, name, value, unit, data);
}

/**
* Returns the metrics aggregator for a given client.
*/
Expand All @@ -52,7 +78,7 @@ export const metricsDefault: Metrics & {
distribution,
set,
gauge,

timing,
/**
* @ignore This is for internal use only.
*/
Expand Down
Loading
Loading