Skip to content

Commit 29752e0

Browse files
Lms24claude
andcommitted
fix(effect): Convert Effect span times to the Sentry clock
Effect timestamps come from its own clock, a fixed origin plus a monotonic clock, which does not correct for clock drift (e.g. after the device slept). Sentry now does, so Effect spans could end up offset from the Sentry spans around them. Start Effect spans on the Sentry clock and convert end and event times by their offset from the span start. This keeps Effect durations and explicitly passed end times. If tracer timing is disabled, Effect passes 0 and we use the Sentry clock instead of producing 1970 timestamps. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
1 parent 779d31b commit 29752e0

2 files changed

Lines changed: 63 additions & 13 deletions

File tree

‎packages/effect/src/tracer.ts‎

Lines changed: 27 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ import {
1111
isObjectLike,
1212
SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN,
1313
startNewTrace,
14+
timestampInSeconds,
1415
withActiveSpan,
1516
withScope,
1617
} from '@sentry/core';
@@ -62,16 +63,8 @@ function deriveOp(name: string): string | undefined {
6263
return undefined;
6364
}
6465

65-
type HrTime = [number, number];
66-
6766
const SENTRY_SPAN_SYMBOL = Symbol.for('@sentry/effect.SentrySpan');
6867

69-
function nanosToHrTime(nanos: bigint): HrTime {
70-
const seconds = Number(nanos / BigInt(1_000_000_000));
71-
const remainingNanos = Number(nanos % BigInt(1_000_000_000));
72-
return [seconds, remainingNanos];
73-
}
74-
7568
interface SentrySpanLike extends EffectTracer.Span {
7669
readonly [SENTRY_SPAN_SYMBOL]: true;
7770
readonly sentrySpan: Span;
@@ -128,6 +121,7 @@ class SentrySpanWrapper implements SentrySpanLike {
128121
public status: EffectTracer.SpanStatus;
129122
public readonly sentrySpan: Span;
130123
public readonly annotations: Context.Context<never>;
124+
private readonly _sentryStartTime: number;
131125

132126
public constructor(
133127
public readonly name: string,
@@ -137,6 +131,7 @@ class SentrySpanWrapper implements SentrySpanLike {
137131
startTime: bigint,
138132
public readonly kind: EffectTracer.SpanKind,
139133
existingSpan: Span,
134+
sentryStartTime: number,
140135
) {
141136
this[SENTRY_SPAN_SYMBOL] = true as const;
142137
this._tag = 'Span' as const;
@@ -145,6 +140,7 @@ class SentrySpanWrapper implements SentrySpanLike {
145140
this.links = [...links];
146141
this.sentrySpan = existingSpan;
147142
this.annotations = context;
143+
this._sentryStartTime = sentryStartTime;
148144

149145
const spanContext = this.sentrySpan.spanContext();
150146
this.spanId = spanContext.spanId;
@@ -188,15 +184,31 @@ class SentrySpanWrapper implements SentrySpanLike {
188184
this.sentrySpan.setStatus({ code: 1 });
189185
}
190186

191-
this.sentrySpan.end(nanosToHrTime(endTime));
187+
this.sentrySpan.end(this._toSentryTime(endTime));
192188
}
193189

194190
public event(name: string, startTime: bigint, attributes?: Record<string, unknown>): void {
195191
if (!this.sentrySpan.isRecording()) {
196192
return;
197193
}
198194

199-
this.sentrySpan.addEvent(name, attributes as Parameters<Span['addEvent']>[1], nanosToHrTime(startTime));
195+
this.sentrySpan.addEvent(name, attributes as Parameters<Span['addEvent']>[1], this._toSentryTime(startTime));
196+
}
197+
198+
/**
199+
* Converts an Effect time to Sentry's clock by adding its offset from the span's start.
200+
*
201+
* Effect's clock doesn't correct for clock drift (e.g. after the device slept), so its absolute times can be off
202+
* from the Sentry spans around this one. Its durations are still correct, and this way we also respect end times
203+
* that were passed explicitly.
204+
*/
205+
private _toSentryTime(effectTime: bigint): number | undefined {
206+
// Effect passes 0 if tracer timing is disabled. Sentry then takes the current time.
207+
if (!effectTime || !this.status.startTime) {
208+
return undefined;
209+
}
210+
211+
return this._sentryStartTime + Number(effectTime - this.status.startTime) / 1e9;
200212
}
201213
}
202214

@@ -382,11 +394,14 @@ function createSentrySpan(
382394
const op = deriveOp(name);
383395
const origin = deriveOrigin(name);
384396

397+
// Effect calls the tracer when the span starts, so we start it on Sentry's clock and convert later Effect times
398+
// relative to this (see `_toSentryTime`).
399+
const sentryStartTime = timestampInSeconds();
385400
const newSpan = startSentrySpan(
386401
startInactiveSpan,
387402
{
388403
name,
389-
startTime: nanosToHrTime(startTime),
404+
startTime: sentryStartTime,
390405
// Setting these to `undefined` would strip the core defaults instead of leaving them in place.
391406
attributes: {
392407
...(op && { [SENTRY_OP]: op }),
@@ -398,7 +413,7 @@ function createSentrySpan(
398413
);
399414
markEffectSpan(newSpan);
400415

401-
return new SentrySpanWrapper(name, parent, context, links, startTime, kind, newSpan);
416+
return new SentrySpanWrapper(name, parent, context, links, startTime, kind, newSpan, sentryStartTime);
402417
}
403418

404419
const makeSentryTracerV3 = (

‎packages/effect/test/tracer.test.ts‎

Lines changed: 36 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,8 @@ import * as sentryCore from '@sentry/core';
33
import * as sentryCoreBrowser from '@sentry/core/browser';
44
import { SEMANTIC_ATTRIBUTE_SENTRY_OP, SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN } from '@sentry/core';
55
import { ServerRuntimeClient } from '@sentry/core/server';
6-
import { Effect } from 'effect';
6+
import { Effect, Exit } from 'effect';
7+
import { TestClock } from 'effect/testing';
78
import * as Tracer from 'effect/Tracer';
89
import { afterEach, beforeEach, vi } from 'vitest';
910
import { SentryEffectTracer as clientTracer } from '../src/client/tracer';
@@ -197,6 +198,40 @@ describe.each(VARIANTS)('SentryEffectTracer ($variant)', ({ variant, tracer, spa
197198

198199
// A name we cannot map belongs to user code or a third-party library. Leaving op and origin unset
199200
// keeps the core defaults (no op, `manual` origin) rather than claiming we instrumented the span.
201+
it.effect("starts spans on Sentry's clock and keeps Effect's duration for an explicit end time", () =>
202+
Effect.gen(function* () {
203+
const end = vi.fn();
204+
const addEvent = vi.fn();
205+
let sentryStartTime: number | undefined;
206+
vi.spyOn(spanApi, 'startInactiveSpan').mockImplementation(options => {
207+
sentryStartTime = options.startTime as number;
208+
return mockSpan({ end, addEvent });
209+
});
210+
211+
// `it.effect` runs on Effect's `TestClock`, which is far from the wall clock.
212+
yield* TestClock.adjust('1 hour');
213+
const span = yield* Effect.makeSpan('manual-span');
214+
span.event('my-event', span.status.startTime + BigInt(1_000_000_000));
215+
span.end(span.status.startTime + BigInt(2_500_000_000), Exit.void);
216+
217+
expect(sentryStartTime).toBeCloseTo(Date.now() / 1000, 0);
218+
expect(addEvent).toHaveBeenCalledWith('my-event', undefined, sentryStartTime! + 1);
219+
expect(end).toHaveBeenCalledWith(sentryStartTime! + 2.5);
220+
}).pipe(withSentryTracer),
221+
);
222+
223+
it.effect("uses Sentry's clock for the end time if Effect's tracer timing is disabled", () =>
224+
Effect.gen(function* () {
225+
const end = vi.fn();
226+
vi.spyOn(spanApi, 'startInactiveSpan').mockImplementation(() => mockSpan({ end }));
227+
228+
yield* TestClock.adjust('1 hour');
229+
yield* Effect.withSpan('untimed-span')(Effect.succeed('ok')).pipe(Effect.withTracerTiming(false));
230+
231+
expect(end).toHaveBeenCalledWith(undefined);
232+
}).pipe(withSentryTracer),
233+
);
234+
200235
it.effect('leaves origin and op unset for spans it cannot map', () =>
201236
Effect.gen(function* () {
202237
const attributes = yield* attributesFor('my-operation');

0 commit comments

Comments
 (0)