Skip to content

Commit

Permalink
feat(core): Add span.end() to replace span.finish() (#9954)
Browse files Browse the repository at this point in the history
To align with OTEL spans.

This also deprecates `span.finish()`, and also makes sure that `end()`
accepts both ms as well as s timestmaps (to align this with OTEL in the
future, which accepts ms only).

---------

Co-authored-by: Yagiz Nizipli <yagiz@nizipli.com>
  • Loading branch information
mydea and anonrig committed Dec 21, 2023
1 parent 12a4fce commit a04e780
Show file tree
Hide file tree
Showing 105 changed files with 472 additions and 299 deletions.
8 changes: 4 additions & 4 deletions packages/angular/src/tracing.ts
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ export class TraceService implements OnDestroy {

if (activeTransaction) {
if (this._routingSpan) {
this._routingSpan.finish();
this._routingSpan.end();
}
this._routingSpan = activeTransaction.startChild({
description: `${navigationEvent.url}`,
Expand Down Expand Up @@ -131,7 +131,7 @@ export class TraceService implements OnDestroy {
if (this._routingSpan) {
runOutsideAngular(() => {
// eslint-disable-next-line @typescript-eslint/no-non-null-assertion
this._routingSpan!.finish();
this._routingSpan!.end();
});
this._routingSpan = null;
}
Expand Down Expand Up @@ -196,7 +196,7 @@ export class TraceDirective implements OnInit, AfterViewInit {
*/
public ngAfterViewInit(): void {
if (this._tracingSpan) {
this._tracingSpan.finish();
this._tracingSpan.end();
}
}
}
Expand Down Expand Up @@ -239,7 +239,7 @@ export function TraceClassDecorator(): ClassDecorator {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
target.prototype.ngAfterViewInit = function (...args: any[]): ReturnType<typeof originalAfterViewInit> {
if (tracingSpan) {
tracingSpan.finish();
tracingSpan.end();
}
if (originalAfterViewInit) {
return originalAfterViewInit.apply(this, args);
Expand Down
14 changes: 7 additions & 7 deletions packages/angular/test/tracing.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -154,7 +154,7 @@ describe('Angular Tracing', () => {

const finishMock = jest.fn();
transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

await env.navigateInAngular('/');
Expand All @@ -173,7 +173,7 @@ describe('Angular Tracing', () => {

const finishMock = jest.fn();
transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

await env.navigateInAngular('/');
Expand All @@ -199,7 +199,7 @@ describe('Angular Tracing', () => {

const finishMock = jest.fn();
transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

await env.navigateInAngular('/somewhere');
Expand Down Expand Up @@ -233,7 +233,7 @@ describe('Angular Tracing', () => {

const finishMock = jest.fn();
transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

await env.navigateInAngular('/cancel');
Expand Down Expand Up @@ -376,7 +376,7 @@ describe('Angular Tracing', () => {
});

transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

directive.componentName = 'test-component';
Expand All @@ -403,7 +403,7 @@ describe('Angular Tracing', () => {
});

transaction.startChild = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

directive.ngOnInit();
Expand Down Expand Up @@ -437,7 +437,7 @@ describe('Angular Tracing', () => {
it('Instruments `ngOnInit` and `ngAfterViewInit` methods of the decorated class', async () => {
const finishMock = jest.fn();
const startChildMock = jest.fn(() => ({
finish: finishMock,
end: finishMock,
}));

const customStartTransaction = jest.fn((ctx: any) => {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ async function run() {
await new Promise(resolve => setTimeout(resolve, 1));

// span_1 finishes
span_1.finish();
span_1.end();

// span_2 doesn't finish
const span_2 = transaction.startChild({ op: 'span_2' });
Expand All @@ -24,12 +24,12 @@ async function run() {
const span_4 = span_3.startChild({ op: 'span_4', data: { qux: 'quux' } });

// span_5 is another child of span_3 but finishes.
const span_5 = span_3.startChild({ op: 'span_5' }).finish();
const span_5 = span_3.startChild({ op: 'span_5' }).end();

// span_3 also finishes
span_3.finish();
span_3.end();

transaction.finish();
transaction.end();
}

run();
Original file line number Diff line number Diff line change
Expand Up @@ -7,5 +7,5 @@ const circularObject = chicken;
const transaction = Sentry.startTransaction({ name: 'circular_object_test_transaction', data: circularObject });
const span = transaction.startChild({ op: 'circular_object_test_span', data: circularObject });

span.finish();
transaction.finish();
span.end();
transaction.end();
Original file line number Diff line number Diff line change
Expand Up @@ -5,4 +5,4 @@ transaction.setMeasurement('metric.bar', 1337, 'nanoseconds');
transaction.setMeasurement('metric.baz', 99, 's');
transaction.setMeasurement('metric.baz', 1);

transaction.finish();
transaction.end();
14 changes: 7 additions & 7 deletions packages/browser/src/profiling/hubextensions.ts
Original file line number Diff line number Diff line change
Expand Up @@ -143,34 +143,34 @@ export function startProfileForTransaction(transaction: Transaction): Transactio
onProfileHandler();
}, MAX_PROFILE_DURATION_MS);

// We need to reference the original finish call to avoid creating an infinite loop
const originalFinish = transaction.finish.bind(transaction);
// We need to reference the original end call to avoid creating an infinite loop
const originalEnd = transaction.end.bind(transaction);

/**
* Wraps startTransaction and stopTransaction with profiling related logic.
* startProfiling is called after the call to startTransaction in order to avoid our own code from
* being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction.
*/
function profilingWrappedTransactionFinish(): Transaction {
function profilingWrappedTransactionEnd(): Transaction {
if (!transaction) {
return originalFinish();
return originalEnd();
}
// onProfileHandler should always return the same profile even if this is called multiple times.
// Always call onProfileHandler to ensure stopProfiling is called and the timeout is cleared.
void onProfileHandler().then(
() => {
transaction.setContext('profile', { profile_id: profileId, start_timestamp: startTimestamp });
originalFinish();
originalEnd();
},
() => {
// If onProfileHandler fails, we still want to call the original finish method.
originalFinish();
originalEnd();
},
);

return transaction;
}

transaction.finish = profilingWrappedTransactionFinish;
transaction.end = profilingWrappedTransactionEnd;
return transaction;
}
2 changes: 1 addition & 1 deletion packages/browser/test/unit/profiling/integration.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ describe('BrowserProfilingIntegration', () => {

const currentTransaction = Sentry.getCurrentHub().getScope().getTransaction();
expect(currentTransaction?.op).toBe('pageload');
currentTransaction?.finish();
currentTransaction?.end();
await client?.flush(1000);

expect(send).toHaveBeenCalledTimes(1);
Expand Down
2 changes: 1 addition & 1 deletion packages/core/src/exports.ts
Original file line number Diff line number Diff line change
Expand Up @@ -179,7 +179,7 @@ export function withScope<T>(callback: (scope: Scope) => T): T {
*
* Every child span must be finished before the transaction is finished, otherwise the unfinished spans are discarded.
*
* The transaction must be finished with a call to its `.finish()` method, at which point the transaction with all its
* The transaction must be finished with a call to its `.end()` method, at which point the transaction with all its
* finished child spans will be sent to Sentry.
*
* NOTE: This function should only be used for *manual* instrumentation. Auto-instrumentation should call
Expand Down
35 changes: 20 additions & 15 deletions packages/core/src/tracing/idletransaction.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import type { Hub } from '../hub';
import type { Span } from './span';
import { SpanRecorder } from './span';
import { Transaction } from './transaction';
import { ensureTimestampInSeconds } from './utils';

export const TRACING_DEFAULTS = {
idleTimeout: 1000,
Expand Down Expand Up @@ -45,10 +46,12 @@ export class IdleTransactionSpanRecorder extends SpanRecorder {
// We should make sure we do not push and pop activities for
// the transaction that this span recorder belongs to.
if (span.spanId !== this.transactionSpanId) {
// We patch span.finish() to pop an activity after setting an endTimestamp.
span.finish = (endTimestamp?: number) => {
span.endTimestamp = typeof endTimestamp === 'number' ? endTimestamp : timestampInSeconds();
// We patch span.end() to pop an activity after setting an endTimestamp.
// eslint-disable-next-line @typescript-eslint/unbound-method
const originalEnd = span.end;
span.end = (...rest: unknown[]) => {
this._popActivity(span.spanId);
return originalEnd.apply(span, rest);
};

// We should only push new activities if the span does not have an end timestamp.
Expand Down Expand Up @@ -129,13 +132,15 @@ export class IdleTransaction extends Transaction {
if (!this._finished) {
this.setStatus('deadline_exceeded');
this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[3];
this.finish();
this.end();
}
}, this._finalTimeout);
}

/** {@inheritDoc} */
public finish(endTimestamp: number = timestampInSeconds()): string | undefined {
public end(endTimestamp: number = timestampInSeconds()): string | undefined {
const endTimestampInS = ensureTimestampInSeconds(endTimestamp);

this._finished = true;
this.activities = {};

Expand All @@ -145,7 +150,7 @@ export class IdleTransaction extends Transaction {

if (this.spanRecorder) {
DEBUG_BUILD &&
logger.log('[Tracing] finishing IdleTransaction', new Date(endTimestamp * 1000).toISOString(), this.op);
logger.log('[Tracing] finishing IdleTransaction', new Date(endTimestampInS * 1000).toISOString(), this.op);

for (const callback of this._beforeFinishCallbacks) {
callback(this, endTimestamp);
Expand All @@ -159,13 +164,13 @@ export class IdleTransaction extends Transaction {

// We cancel all pending spans with status "cancelled" to indicate the idle transaction was finished early
if (!span.endTimestamp) {
span.endTimestamp = endTimestamp;
span.endTimestamp = endTimestampInS;
span.setStatus('cancelled');
DEBUG_BUILD &&
logger.log('[Tracing] cancelling span since transaction ended early', JSON.stringify(span, undefined, 2));
}

const spanStartedBeforeTransactionFinish = span.startTimestamp < endTimestamp;
const spanStartedBeforeTransactionFinish = span.startTimestamp < endTimestampInS;

// Add a delta with idle timeout so that we prevent false positives
const timeoutWithMarginOfError = (this._finalTimeout + this._idleTimeout) / 1000;
Expand Down Expand Up @@ -196,7 +201,7 @@ export class IdleTransaction extends Transaction {
}
}

return super.finish(endTimestamp);
return super.end(endTimestamp);
}

/**
Expand Down Expand Up @@ -244,7 +249,7 @@ export class IdleTransaction extends Transaction {
* with the last child span.
*/
public cancelIdleTimeout(
endTimestamp?: Parameters<IdleTransaction['finish']>[0],
endTimestamp?: Parameters<IdleTransaction['end']>[0],
{
restartOnChildSpanChange,
}: {
Expand All @@ -260,7 +265,7 @@ export class IdleTransaction extends Transaction {

if (Object.keys(this.activities).length === 0 && this._idleTimeoutCanceledPermanently) {
this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[5];
this.finish(endTimestamp);
this.end(endTimestamp);
}
}
}
Expand All @@ -281,12 +286,12 @@ export class IdleTransaction extends Transaction {
/**
* Restarts idle timeout, if there is no running idle timeout it will start one.
*/
private _restartIdleTimeout(endTimestamp?: Parameters<IdleTransaction['finish']>[0]): void {
private _restartIdleTimeout(endTimestamp?: Parameters<IdleTransaction['end']>[0]): void {
this.cancelIdleTimeout();
this._idleTimeoutID = setTimeout(() => {
if (!this._finished && Object.keys(this.activities).length === 0) {
this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[1];
this.finish(endTimestamp);
this.end(endTimestamp);
}
}, this._idleTimeout);
}
Expand Down Expand Up @@ -318,7 +323,7 @@ export class IdleTransaction extends Transaction {
const endTimestamp = timestampInSeconds();
if (this._idleTimeoutCanceledPermanently) {
this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[5];
this.finish(endTimestamp);
this.end(endTimestamp);
} else {
// We need to add the timeout here to have the real endtimestamp of the transaction
// Remember timestampInSeconds is in seconds, timeout is in ms
Expand Down Expand Up @@ -351,7 +356,7 @@ export class IdleTransaction extends Transaction {
DEBUG_BUILD && logger.log('[Tracing] Transaction finished because of no change for 3 heart beats');
this.setStatus('deadline_exceeded');
this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[0];
this.finish();
this.end();
} else {
this._pingHeartbeat();
}
Expand Down
11 changes: 10 additions & 1 deletion packages/core/src/tracing/span.ts
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import type {
import { dropUndefinedKeys, generateSentryTraceHeader, logger, timestampInSeconds, uuid4 } from '@sentry/utils';

import { DEBUG_BUILD } from '../debug-build';
import { ensureTimestampInSeconds } from './utils';

/**
* Keeps track of finished spans for a given transaction
Expand Down Expand Up @@ -259,8 +260,15 @@ export class Span implements SpanInterface {

/**
* @inheritDoc
*
* @deprecated Use `.end()` instead.
*/
public finish(endTimestamp?: number): void {
return this.end(endTimestamp);
}

/** @inheritdoc */
public end(endTimestamp?: number): void {
if (
DEBUG_BUILD &&
// Don't call this for transactions
Expand All @@ -273,7 +281,8 @@ export class Span implements SpanInterface {
}
}

this.endTimestamp = typeof endTimestamp === 'number' ? endTimestamp : timestampInSeconds();
this.endTimestamp =
typeof endTimestamp === 'number' ? ensureTimestampInSeconds(endTimestamp) : timestampInSeconds();
}

/**
Expand Down
6 changes: 3 additions & 3 deletions packages/core/src/tracing/trace.ts
Original file line number Diff line number Diff line change
Expand Up @@ -39,7 +39,7 @@ export function trace<T>(
scope.setSpan(activeSpan);

function finishAndSetSpan(): void {
activeSpan && activeSpan.finish();
activeSpan && activeSpan.end();
scope.setSpan(parentSpan);
}

Expand Down Expand Up @@ -97,7 +97,7 @@ export function startSpan<T>(context: TransactionContext, callback: (span: Span
scope.setSpan(activeSpan);

function finishAndSetSpan(): void {
activeSpan && activeSpan.finish();
activeSpan && activeSpan.end();
scope.setSpan(parentSpan);
}

Expand Down Expand Up @@ -157,7 +157,7 @@ export function startSpanManual<T>(
scope.setSpan(activeSpan);

function finishAndSetSpan(): void {
activeSpan && activeSpan.finish();
activeSpan && activeSpan.end();
scope.setSpan(parentSpan);
}

Expand Down

0 comments on commit a04e780

Please sign in to comment.