Skip to content

Commit 427a5d7

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 1dc236f commit 427a5d7

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
@@ -10,6 +10,7 @@ import {
1010
getDefaultCurrentScope,
1111
isObjectLike,
1212
startNewTrace,
13+
timestampInSeconds,
1314
withActiveSpan,
1415
withScope,
1516
} from '@sentry/core';
@@ -61,16 +62,8 @@ function deriveOp(name: string): string | undefined {
6162
return undefined;
6263
}
6364

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

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

131125
public constructor(
132126
public readonly name: string,
@@ -136,6 +130,7 @@ class SentrySpanWrapper implements SentrySpanLike {
136130
startTime: bigint,
137131
public readonly kind: EffectTracer.SpanKind,
138132
existingSpan: Span,
133+
sentryStartTime: number,
139134
) {
140135
this[SENTRY_SPAN_SYMBOL] = true as const;
141136
this._tag = 'Span' as const;
@@ -144,6 +139,7 @@ class SentrySpanWrapper implements SentrySpanLike {
144139
this.links = [...links];
145140
this.sentrySpan = existingSpan;
146141
this.annotations = context;
142+
this._sentryStartTime = sentryStartTime;
147143

148144
const spanContext = this.sentrySpan.spanContext();
149145
this.spanId = spanContext.spanId;
@@ -187,15 +183,31 @@ class SentrySpanWrapper implements SentrySpanLike {
187183
this.sentrySpan.setStatus({ code: 1 });
188184
}
189185

190-
this.sentrySpan.end(nanosToHrTime(endTime));
186+
this.sentrySpan.end(this._toSentryTime(endTime));
191187
}
192188

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

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

@@ -381,11 +393,14 @@ function createSentrySpan(
381393
const op = deriveOp(name);
382394
const origin = deriveOrigin(name);
383395

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

400-
return new SentrySpanWrapper(name, parent, context, links, startTime, kind, newSpan);
415+
return new SentrySpanWrapper(name, parent, context, links, startTime, kind, newSpan, sentryStartTime);
401416
}
402417

403418
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 { describe, expect, it } from '@effect/vitest';
33
import * as sentryCore from '@sentry/core';
44
import * as sentryCoreBrowser from '@sentry/core/browser';
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)