Skip to content

Commit

Permalink
feat(core): Deprecate span startTimestamp & endTimestamp (#10192)
Browse files Browse the repository at this point in the history
Instead, you can use `spanToJSON()` to _read_ the timestamps. Updating
timestamps after span creation will not be possible in v8.

Also ensure that `span.end()` can only be called once - we already do
that for transactions, and it saves us from checking e.g.
`span.endTimestamp` before calling `span.end()`. This is also aligned
with how OTEL does it (they emit a warning if trying to end a span
twice).
  • Loading branch information
mydea committed Jan 16, 2024
1 parent 569d782 commit 2974df6
Show file tree
Hide file tree
Showing 24 changed files with 206 additions and 134 deletions.
3 changes: 3 additions & 0 deletions MIGRATION.md
Original file line number Diff line number Diff line change
Expand Up @@ -183,6 +183,9 @@ In v8, the Span class is heavily reworked. The following properties & methods ar
- `transaction.setMeasurement()`: Use `Sentry.setMeasurement()` instead. In v8, setting measurements will be limited to
the currently active root span.
- `transaction.setName()`: Set the name with `.updateName()` and the source with `.setAttribute()` instead.
- `span.startTimestamp`: use `spanToJSON(span).start_timestamp` instead. You cannot update this anymore in v8.
- `span.endTimestamp`: use `spanToJSON(span).timestamp` instead. You cannot update this anymore in v8. You can pass a
custom end timestamp to `span.end(endTimestamp)`.

## Deprecate `pushScope` & `popScope` in favor of `withScope`

Expand Down
13 changes: 7 additions & 6 deletions packages/core/src/tracing/idletransaction.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ import { logger, timestampInSeconds } from '@sentry/utils';

import { DEBUG_BUILD } from '../debug-build';
import type { Hub } from '../hub';
import { spanTimeInputToSeconds } from '../utils/spanUtils';
import { spanTimeInputToSeconds, spanToJSON } from '../utils/spanUtils';
import type { Span } from './span';
import { SpanRecorder } from './span';
import { Transaction } from './transaction';
Expand Down Expand Up @@ -55,7 +55,7 @@ export class IdleTransactionSpanRecorder extends SpanRecorder {
};

// We should only push new activities if the span does not have an end timestamp.
if (span.endTimestamp === undefined) {
if (spanToJSON(span).timestamp === undefined) {
this._pushActivity(span.spanContext().spanId);
}
}
Expand Down Expand Up @@ -167,18 +167,19 @@ 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 = endTimestampInS;
if (!spanToJSON(span).timestamp) {
span.setStatus('cancelled');
span.end(endTimestampInS);
DEBUG_BUILD &&
logger.log('[Tracing] cancelling span since transaction ended early', JSON.stringify(span, undefined, 2));
}

const spanStartedBeforeTransactionFinish = span.startTimestamp < endTimestampInS;
const { start_timestamp: startTime, timestamp: endTime } = spanToJSON(span);
const spanStartedBeforeTransactionFinish = startTime && startTime < endTimestampInS;

// Add a delta with idle timeout so that we prevent false positives
const timeoutWithMarginOfError = (this._finalTimeout + this._idleTimeout) / 1000;
const spanEndedBeforeFinalTimeout = span.endTimestamp - this.startTimestamp < timeoutWithMarginOfError;
const spanEndedBeforeFinalTimeout = endTime && startTime && endTime - startTime < timeoutWithMarginOfError;

if (DEBUG_BUILD) {
const stringifiedSpan = JSON.stringify(span, undefined, 2);
Expand Down
70 changes: 50 additions & 20 deletions packages/core/src/tracing/span.ts
Original file line number Diff line number Diff line change
Expand Up @@ -71,16 +71,6 @@ export class Span implements SpanInterface {
*/
public status?: SpanStatusType | string;

/**
* Timestamp in seconds when the span was created.
*/
public startTimestamp: number;

/**
* Timestamp in seconds when the span ended.
*/
public endTimestamp?: number;

/**
* @inheritDoc
*/
Expand Down Expand Up @@ -131,6 +121,10 @@ export class Span implements SpanInterface {
protected _sampled: boolean | undefined;
protected _name?: string;
protected _attributes: SpanAttributes;
/** Epoch timestamp in seconds when the span started. */
protected _startTime: number;
/** Epoch timestamp in seconds when the span ended. */
protected _endTime?: number;

private _logMessage?: string;

Expand All @@ -144,7 +138,7 @@ export class Span implements SpanInterface {
public constructor(spanContext: SpanContext = {}) {
this._traceId = spanContext.traceId || uuid4();
this._spanId = spanContext.spanId || uuid4().substring(16);
this.startTimestamp = spanContext.startTimestamp || timestampInSeconds();
this._startTime = spanContext.startTimestamp || timestampInSeconds();
// eslint-disable-next-line deprecation/deprecation
this.tags = spanContext.tags ? { ...spanContext.tags } : {};
// eslint-disable-next-line deprecation/deprecation
Expand All @@ -170,7 +164,7 @@ export class Span implements SpanInterface {
this.status = spanContext.status;
}
if (spanContext.endTimestamp) {
this.endTimestamp = spanContext.endTimestamp;
this._endTime = spanContext.endTimestamp;
}
}

Expand Down Expand Up @@ -273,6 +267,38 @@ export class Span implements SpanInterface {
this._attributes = attributes;
}

/**
* Timestamp in seconds (epoch time) indicating when the span started.
* @deprecated Use `spanToJSON()` instead.
*/
public get startTimestamp(): number {
return this._startTime;
}

/**
* Timestamp in seconds (epoch time) indicating when the span started.
* @deprecated In v8, you will not be able to update the span start time after creation.
*/
public set startTimestamp(startTime: number) {
this._startTime = startTime;
}

/**
* Timestamp in seconds when the span ended.
* @deprecated Use `spanToJSON()` instead.
*/
public get endTimestamp(): number | undefined {
return this._endTime;
}

/**
* Timestamp in seconds when the span ended.
* @deprecated Set the end time via `span.end()` instead.
*/
public set endTimestamp(endTime: number | undefined) {
this._endTime = endTime;
}

/* eslint-enable @typescript-eslint/member-ordering */

/** @inheritdoc */
Expand Down Expand Up @@ -426,6 +452,10 @@ export class Span implements SpanInterface {

/** @inheritdoc */
public end(endTimestamp?: SpanTimeInput): void {
// If already ended, skip
if (this._endTime) {
return;
}
const rootSpan = getRootSpan(this);
if (
DEBUG_BUILD &&
Expand All @@ -439,7 +469,7 @@ export class Span implements SpanInterface {
}
}

this.endTimestamp = spanTimeInputToSeconds(endTimestamp);
this._endTime = spanTimeInputToSeconds(endTimestamp);
}

/**
Expand All @@ -460,12 +490,12 @@ export class Span implements SpanInterface {
return dropUndefinedKeys({
data: this._getData(),
description: this._name,
endTimestamp: this.endTimestamp,
endTimestamp: this._endTime,
op: this.op,
parentSpanId: this.parentSpanId,
sampled: this._sampled,
spanId: this._spanId,
startTimestamp: this.startTimestamp,
startTimestamp: this._startTime,
status: this.status,
// eslint-disable-next-line deprecation/deprecation
tags: this.tags,
Expand All @@ -483,12 +513,12 @@ export class Span implements SpanInterface {
this.data = spanContext.data || {};
// eslint-disable-next-line deprecation/deprecation
this._name = spanContext.name || spanContext.description;
this.endTimestamp = spanContext.endTimestamp;
this._endTime = spanContext.endTimestamp;
this.op = spanContext.op;
this.parentSpanId = spanContext.parentSpanId;
this._sampled = spanContext.sampled;
this._spanId = spanContext.spanId || this._spanId;
this.startTimestamp = spanContext.startTimestamp || this.startTimestamp;
this._startTime = spanContext.startTimestamp || this._startTime;
this.status = spanContext.status;
// eslint-disable-next-line deprecation/deprecation
this.tags = spanContext.tags || {};
Expand Down Expand Up @@ -521,19 +551,19 @@ export class Span implements SpanInterface {
op: this.op,
parent_span_id: this.parentSpanId,
span_id: this._spanId,
start_timestamp: this.startTimestamp,
start_timestamp: this._startTime,
status: this.status,
// eslint-disable-next-line deprecation/deprecation
tags: Object.keys(this.tags).length > 0 ? this.tags : undefined,
timestamp: this.endTimestamp,
timestamp: this._endTime,
trace_id: this._traceId,
origin: this.origin,
});
}

/** @inheritdoc */
public isRecording(): boolean {
return !this.endTimestamp && !!this._sampled;
return !this._endTime && !!this._sampled;
}

/**
Expand Down
2 changes: 1 addition & 1 deletion packages/core/src/tracing/trace.ts
Original file line number Diff line number Diff line change
Expand Up @@ -242,7 +242,7 @@ export function startSpanManual<T>(
() => callback(activeSpan, finishAndSetSpan),
() => {
// Only update the span status if it hasn't been changed yet, and the span is not yet finished
if (activeSpan && !activeSpan.endTimestamp && (!activeSpan.status || activeSpan.status === 'ok')) {
if (activeSpan && activeSpan.isRecording() && (!activeSpan.status || activeSpan.status === 'ok')) {
activeSpan.setStatus('internal_error');
}
},
Expand Down
22 changes: 11 additions & 11 deletions packages/core/src/tracing/transaction.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ import { DEBUG_BUILD } from '../debug-build';
import type { Hub } from '../hub';
import { getCurrentHub } from '../hub';
import { SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE, SEMANTIC_ATTRIBUTE_SENTRY_SOURCE } from '../semanticAttributes';
import { spanTimeInputToSeconds, spanToTraceContext } from '../utils/spanUtils';
import { spanTimeInputToSeconds, spanToJSON, spanToTraceContext } from '../utils/spanUtils';
import { getDynamicSamplingContextFromSpan } from './dynamicSamplingContext';
import { Span as SpanClass, SpanRecorder } from './span';

Expand Down Expand Up @@ -257,7 +257,7 @@ export class Transaction extends SpanClass implements TransactionInterface {
*/
protected _finishTransaction(endTimestamp?: number): TransactionEvent | undefined {
// This transaction is already finished, so we should not flush it again.
if (this.endTimestamp !== undefined) {
if (this._endTime !== undefined) {
return undefined;
}

Expand Down Expand Up @@ -286,15 +286,15 @@ export class Transaction extends SpanClass implements TransactionInterface {
return undefined;
}

const finishedSpans = this.spanRecorder ? this.spanRecorder.spans.filter(s => s !== this && s.endTimestamp) : [];
const finishedSpans = this.spanRecorder
? this.spanRecorder.spans.filter(span => span !== this && spanToJSON(span).timestamp)
: [];

if (this._trimEnd && finishedSpans.length > 0) {
this.endTimestamp = finishedSpans.reduce((prev: SpanClass, current: SpanClass) => {
if (prev.endTimestamp && current.endTimestamp) {
return prev.endTimestamp > current.endTimestamp ? prev : current;
}
return prev;
}).endTimestamp;
const endTimes = finishedSpans.map(span => spanToJSON(span).timestamp).filter(Boolean) as number[];
this._endTime = endTimes.reduce((prev, current) => {
return prev > current ? prev : current;
});
}

// eslint-disable-next-line deprecation/deprecation
Expand All @@ -310,10 +310,10 @@ export class Transaction extends SpanClass implements TransactionInterface {
},
// TODO: Pass spans serialized via `spanToJSON()` here instead in v8.
spans: finishedSpans,
start_timestamp: this.startTimestamp,
start_timestamp: this._startTime,
// eslint-disable-next-line deprecation/deprecation
tags: this.tags,
timestamp: this.endTimestamp,
timestamp: this._endTime,
transaction: this._name,
type: 'transaction',
sdkProcessingMetadata: {
Expand Down
20 changes: 15 additions & 5 deletions packages/core/test/lib/tracing/span.test.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
import { timestampInSeconds } from '@sentry/utils';
import { Span } from '../../../src';
import { TRACE_FLAG_NONE, TRACE_FLAG_SAMPLED } from '../../../src/utils/spanUtils';
import { TRACE_FLAG_NONE, TRACE_FLAG_SAMPLED, spanToJSON } from '../../../src/utils/spanUtils';

describe('span', () => {
describe('name', () => {
Expand Down Expand Up @@ -186,31 +186,41 @@ describe('span', () => {
const now = timestampInSeconds();
span.end();

expect(span.endTimestamp).toBeGreaterThanOrEqual(now);
expect(spanToJSON(span).timestamp).toBeGreaterThanOrEqual(now);
});

it('works with endTimestamp in seconds', () => {
const span = new Span();
const timestamp = timestampInSeconds() - 1;
span.end(timestamp);

expect(span.endTimestamp).toEqual(timestamp);
expect(spanToJSON(span).timestamp).toEqual(timestamp);
});

it('works with endTimestamp in milliseconds', () => {
const span = new Span();
const timestamp = Date.now() - 1000;
span.end(timestamp);

expect(span.endTimestamp).toEqual(timestamp / 1000);
expect(spanToJSON(span).timestamp).toEqual(timestamp / 1000);
});

it('works with endTimestamp in array form', () => {
const span = new Span();
const seconds = Math.floor(timestampInSeconds() - 1);
span.end([seconds, 0]);

expect(span.endTimestamp).toEqual(seconds);
expect(spanToJSON(span).timestamp).toEqual(seconds);
});

it('skips if span is already ended', () => {
const startTimestamp = timestampInSeconds() - 5;
const endTimestamp = timestampInSeconds() - 1;
const span = new Span({ startTimestamp, endTimestamp });

span.end();

expect(spanToJSON(span).timestamp).toBe(endTimestamp);
});
});

Expand Down
20 changes: 10 additions & 10 deletions packages/core/test/lib/tracing/trace.test.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
import { Hub, addTracingExtensions, getCurrentScope, makeMain } from '../../../src';
import { Hub, addTracingExtensions, getCurrentScope, makeMain, spanToJSON } from '../../../src';
import { Scope } from '../../../src/scope';
import {
Span,
Expand Down Expand Up @@ -183,17 +183,17 @@ describe('startSpan', () => {
let _span: Span | undefined;
startSpan({ name: 'GET users/[id]' }, span => {
expect(span).toBeDefined();
expect(span?.endTimestamp).toBeUndefined();
expect(spanToJSON(span!).timestamp).toBeUndefined();
_span = span as Span;
});

expect(_span).toBeDefined();
expect(_span?.endTimestamp).toBeDefined();
expect(spanToJSON(_span!).timestamp).toBeDefined();
});

it('allows to pass a `startTime`', () => {
const start = startSpan({ name: 'outer', startTime: [1234, 0] }, span => {
return span?.startTimestamp;
return spanToJSON(span!).start_timestamp;
});

expect(start).toEqual(1234);
Expand Down Expand Up @@ -236,9 +236,9 @@ describe('startSpanManual', () => {
it('creates & finishes span', async () => {
startSpanManual({ name: 'GET users/[id]' }, (span, finish) => {
expect(span).toBeDefined();
expect(span?.endTimestamp).toBeUndefined();
expect(spanToJSON(span!).timestamp).toBeUndefined();
finish();
expect(span?.endTimestamp).toBeDefined();
expect(spanToJSON(span!).timestamp).toBeDefined();
});
});

Expand Down Expand Up @@ -286,7 +286,7 @@ describe('startSpanManual', () => {
it('allows to pass a `startTime`', () => {
const start = startSpanManual({ name: 'outer', startTime: [1234, 0] }, span => {
span?.end();
return span?.startTimestamp;
return spanToJSON(span!).start_timestamp;
});

expect(start).toEqual(1234);
Expand All @@ -298,11 +298,11 @@ describe('startInactiveSpan', () => {
const span = startInactiveSpan({ name: 'GET users/[id]' });

expect(span).toBeDefined();
expect(span?.endTimestamp).toBeUndefined();
expect(spanToJSON(span!).timestamp).toBeUndefined();

span?.end();

expect(span?.endTimestamp).toBeDefined();
expect(spanToJSON(span!).timestamp).toBeDefined();
});

it('does not set span on scope', () => {
Expand Down Expand Up @@ -335,7 +335,7 @@ describe('startInactiveSpan', () => {

it('allows to pass a `startTime`', () => {
const span = startInactiveSpan({ name: 'outer', startTime: [1234, 0] });
expect(span?.startTimestamp).toEqual(1234);
expect(spanToJSON(span!).start_timestamp).toEqual(1234);
});
});

Expand Down

0 comments on commit 2974df6

Please sign in to comment.