fix(traces): keep inbound context and flag a future span start

.changeset/traces-context-and-time-fidelity.md

@@ -0,0 +1,5 @@
+---
+'@posthog/core': patch
+---
+
+Forward an inbound `traceparent` whose version is above `00` whole, including the fields that version adds, rather than trimming it to the four this SDK reads. Keep the inbound context when a handle returned with tracing off is passed back as `parent`, so a child no longer starts a fresh trace. Warn when a span's `startTime` is in the future, which costs it its duration.

packages/core/src/traces/index.spec.ts

@@ -1,6 +1,6 @@
 import { PostHogTraces } from './index'
 import { SyncSpanContextManager } from './context'
-import { NOOP_SPAN } from './span'
+import { NOOP_SPAN, inertSpan } from './span'
 import type {
   OtlpSpan,
   OtlpTracesPayload,
@@ -171,6 +171,16 @@ describe('PostHogTraces', () => {
       expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('24 hours'))
       expect(sentSpans()).toHaveLength(1)
     })
+
+    it('warns when a start is in the future, which costs the span its duration', async () => {
+      const traces = createTraces()
+      traces.startSpan('ahead', { startTime: Date.now() + 60 * 60 * 1000 }).end()
+      await traces.flush()
+
+      expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('in the future'))
+      const [span] = sentSpans()
+      expect(span.endTimeUnixNano).toBe(span.startTimeUnixNano)
+    })
   })
 
   describe('trace continuation', () => {
@@ -493,6 +503,49 @@ describe('PostHogTraces', () => {
       expect(traces.startSpan('no-parent')).toBe(NOOP_SPAN)
       expect(traces.startSpan('bad-parent', { parent: 'not-a-traceparent' })).toBe(NOOP_SPAN)
     })
+
+    it('keeps the inbound context when a pass-through handle is used as a parent', () => {
+      // The child is inert either way; what it must not do is drop the context
+      // and leave everything downstream of it on a fresh trace.
+      const traces = createTraces({}, createMockInstance({ optedOut: true }))
+      const parent = traces.startSpan('proxied', { parent: INBOUND_UNSAMPLED, tracestate: 'vendor=abc' })
+
+      const child = traces.startSpan('child', { parent })
+
+      expect(child.traceparent()).toBe(INBOUND_UNSAMPLED)
+      expect(child.tracestate()).toBe('vendor=abc')
+      expect(sentSpans()).toHaveLength(0)
+    })
+
+    it('records nothing for a child of a pass-through once tracing is back on', async () => {
+      // Spec: a child of an inert handle is inert, so this must propagate without
+      // enqueueing a span, even though this instance is recording.
+      const traces = createTraces()
+      const parent = inertSpan({ parent: INBOUND_UNSAMPLED })
+
+      const child = traces.startSpan('child', { parent })
+      child.end()
+      await traces.flush()
+
+      expect(child.traceparent()).toBe(INBOUND_UNSAMPLED)
+      expect(sentSpans()).toHaveLength(0)
+    })
+
+    it('yields a no-op for a child of a no-op', () => {
+      const traces = createTraces()
+      expect(traces.startSpan('child', { parent: NOOP_SPAN })).toBe(NOOP_SPAN)
+    })
+
+    it('survives a parent whose traceparent throws', () => {
+      const traces = createTraces()
+      const hostile = {
+        traceparent: () => {
+          throw new Error('nope')
+        },
+      }
+
+      expect(traces.startSpan('child', { parent: hostile as never })).toBe(NOOP_SPAN)
+    })
   })
 
   describe('auto-context', () => {
@@ -992,6 +1045,49 @@ describe('PostHogTraces', () => {
     })
   })
 
+  describe('flush backoff', () => {
+    it('resumes the depth trigger after a non-retriable drop clears the backlog', async () => {
+      // A 503 burst raises the consecutive-failure count, which disables the
+      // depth trigger. Dropping the poison batch is progress, so the count has to
+      // clear with it or the queue stays on the slow timer while the endpoint is
+      // healthy.
+      mockInstance._sendTracesBatch
+        .mockResolvedValueOnce({ kind: 'retry-later', error: new Error('503') })
+        .mockResolvedValueOnce({ kind: 'fatal', error: new Error('400') })
+        .mockResolvedValue({ kind: 'ok' })
+
+      const traces = createTraces({ maxExportBatchSize: 1, flushIntervalMs: 10_000 })
+      traces.startSpan('poison').end()
+      await flushMicrotasks()
+      await traces.flush()
+      mockInstance._sendTracesBatch.mockClear()
+
+      // Depth trigger only fires again if the failure count was cleared.
+      traces.startSpan('after').end()
+      await flushMicrotasks()
+
+      expect(mockInstance._sendTracesBatch).toHaveBeenCalled()
+    })
+
+    it('resumes the depth trigger after a too-large single-span drop', async () => {
+      mockInstance._sendTracesBatch
+        .mockResolvedValueOnce({ kind: 'retry-later', error: new Error('503') })
+        .mockResolvedValueOnce({ kind: 'too-large' })
+        .mockResolvedValue({ kind: 'ok' })
+
+      const traces = createTraces({ maxExportBatchSize: 1, flushIntervalMs: 10_000 })
+      traces.startSpan('huge').end()
+      await flushMicrotasks()
+      await traces.flush()
+      mockInstance._sendTracesBatch.mockClear()
+
+      traces.startSpan('after').end()
+      await flushMicrotasks()
+
+      expect(mockInstance._sendTracesBatch).toHaveBeenCalled()
+    })
+  })
+
   describe('drop accounting', () => {
     it('still warns about queue-full drops while the endpoint is failing', async () => {
       mockInstance._sendTracesBatch.mockResolvedValue({ kind: 'retry-later', error: new Error('down') })

packages/core/src/traces/index.ts

@@ -8,7 +8,7 @@ import type {
   TraceSdkContext,
   TracesHost,
 } from './types'
-import { NOOP_SPAN, PostHogSpan, describeError, inertSpan, monotonicNow, runWithActiveSpan } from './span'
+import { PostHogSpan, describeError, inertSpan, monotonicNow, runWithActiveSpan } from './span'
 import { newSpanId, newTraceId } from './ids'
 import { parseTraceparent, sanitizeTracestate } from './traceparent'
 import { resolveStartTime, sanitizeName } from './sanitize'
@@ -115,9 +115,11 @@ export class PostHogTraces {
     const explicitParent = options?.parent
     if (explicitParent && typeof explicitParent !== 'string' && !isOwnSpan(explicitParent)) {
       if (looksLikeSpan(explicitParent)) {
-        // A child of a no-op is itself a no-op, never an orphan with invented ids.
+        // Inert like its parent, never an orphan with invented ids — but a
+        // pass-through parent's inbound context carries to the child rather than
+        // the trace ending here.
         this._logger.debug('Span parent is not a span from this SDK; returning an inert span')
-        return NOOP_SPAN
+        return inertSpan(options)
       }
       // No `traceparent()` to read: `req.headers.traceparent` is `string[]` when the
       // header arrives twice, and a span from another tracer exposes `spanContext()`
@@ -523,6 +525,7 @@ export class PostHogTraces {
             remaining -= 1
             removed += 1
             this._recordDrop(1, 'the ingestion endpoint rejected it as too large')
+            this._consecutiveFlushFailures = 0
             this._headBatchFailures = 0
             continue
           }
@@ -560,6 +563,7 @@ export class PostHogTraces {
         this._queue.splice(0, size)
         remaining -= size
         removed += size
+        this._consecutiveFlushFailures = 0
         this._headBatchFailures = 0
         this._recordDrop(size, 'the ingestion endpoint rejected the batch')
       }

packages/core/src/traces/sanitize.ts

@@ -75,6 +75,10 @@ export function resolveStartTime(value: SpanTimeInput | undefined, now: number,
     logger?.debug(
       'Span startTime is more than 24 hours in the past; the server will clamp it to receive time and keep the original in $originalTimestamp'
     )
+  } else if (supplied > now) {
+    // Warned rather than clamped, matching the deep-backdate rule: the value is
+    // the caller's. The duration is what suffers, since the end clamps to it.
+    logger?.debug('Span startTime is in the future; the span may export with a zero duration')
   }
   return supplied
 }

packages/core/src/traces/span.ts

@@ -269,11 +269,26 @@ export class PassThroughSpan extends NoopSpan {
  * caller supplied a usable `parent` header, the shared no-op otherwise.
  */
 export function inertSpan(options?: { parent?: unknown; tracestate?: unknown }): Span {
-  const traceparent = normalizeTraceparent(options?.parent)
+  const parent = options?.parent
+  // A handle parent reports its own context, read behind a guard because a
+  // foreign handle's accessor may throw. A no-op reports none and stays a no-op.
+  const inbound = typeof parent === 'string' || parent == null ? parent : readHandle(parent, 'traceparent')
+  const traceparent = normalizeTraceparent(inbound)
   if (!traceparent) {
     return NOOP_SPAN
   }
-  return new PassThroughSpan(traceparent, sanitizeTracestate(options?.tracestate))
+  const tracestate =
+    typeof parent === 'string' || parent == null ? options?.tracestate : readHandle(parent, 'tracestate')
+  return new PassThroughSpan(traceparent, sanitizeTracestate(tracestate))
+}
+
+function readHandle(parent: unknown, method: 'traceparent' | 'tracestate'): unknown {
+  try {
+    const fn = (parent as Span)[method]
+    return typeof fn === 'function' ? fn.call(parent) : undefined
+  } catch {
+    return undefined
+  }
 }
 
 /**

packages/core/src/traces/traceparent.spec.ts

@@ -140,8 +140,12 @@ describe('normalizeTraceparent', () => {
     expect(normalizeTraceparent(`01-${TRACE_ID}-${SPAN_ID}-01`)).toBe(`01-${TRACE_ID}-${SPAN_ID}-01`)
   })
 
-  it("trims surrounding whitespace, and drops a higher version's trailing fields", () => {
-    expect(normalizeTraceparent(`  01-${TRACE_ID}-${SPAN_ID}-01-extra `)).toBe(`01-${TRACE_ID}-${SPAN_ID}-01`)
+  it("keeps a higher version's trailing fields, so a peer that reads them still can", () => {
+    expect(normalizeTraceparent(`01-${TRACE_ID}-${SPAN_ID}-01-extra`)).toBe(`01-${TRACE_ID}-${SPAN_ID}-01-extra`)
+  })
+
+  it('trims surrounding whitespace', () => {
+    expect(normalizeTraceparent(`  00-${TRACE_ID}-${SPAN_ID}-01 `)).toBe(`00-${TRACE_ID}-${SPAN_ID}-01`)
   })
 
   it.each([

packages/core/src/traces/traceparent.ts

@@ -70,13 +70,14 @@ function matchTraceparent(value: unknown): TraceparentFields | undefined {
 }
 
 /**
- * The canonical form of an inbound `traceparent`, or `undefined` when it is
- * malformed. Version and flags are carried through as received, so a service
- * that forwards this value continues the caller's trace exactly as sent.
+ * The inbound `traceparent` as received, or `undefined` when it is malformed.
+ *
+ * Returned whole rather than rebuilt: a version above `00` may append fields
+ * this SDK does not read, and rebuilding would forward a header still labelled
+ * with that version but missing what the version defines.
  */
 export function normalizeTraceparent(value: unknown): string | undefined {
-  const fields = matchTraceparent(value)
-  return fields && `${fields.version}-${fields.traceId}-${fields.spanId}-${fields.flags}`
+  return matchTraceparent(value) && (value as string).trim()
 }
 
 /** The W3C sampled bit, set on a trace this SDK started. */