diff --git a/.changeset/node-distributed-tracing.md b/.changeset/node-distributed-tracing.md new file mode 100644 index 0000000000..02f3b7a044 --- /dev/null +++ b/.changeset/node-distributed-tracing.md @@ -0,0 +1,9 @@ +--- +'posthog-node': minor +'@posthog/core': minor +'@posthog/types': minor +--- + +Add distributed tracing to posthog-node behind a new `traces` client option. `withSpan` / `startSpan` / `getActiveSpan` create OpenTelemetry-shaped spans that export to PostHog with no OpenTelemetry dependency, and spans created inside a request context automatically carry `posthogDistinctId` and `sessionId` so traces link back to people and sessions. Tracing stays off until `traces` is configured, and the API is marked `@experimental` while PostHog's tracing product is in beta. + +Spans, logs and metrics now share one OTLP attribute encoder, so a `bigint` attribute is sent as an int64 rather than a plain string, and an attribute whose getter throws costs only that key instead of the whole record. diff --git a/packages/core/src/__tests__/posthog.flush.spec.ts b/packages/core/src/__tests__/posthog.flush.spec.ts index 1372d6ff87..d3a2f1bded 100644 --- a/packages/core/src/__tests__/posthog.flush.spec.ts +++ b/packages/core/src/__tests__/posthog.flush.spec.ts @@ -762,11 +762,12 @@ describe('PostHog Core', () => { }) describe('OTLP batch senders', () => { - // Both share one `_sendOtlpBatch`; the table pins them to the same + // All three share one `_sendOtlpBatch`; the table pins them to the same // classification so a wrapper can't reintroduce a per-signal retry policy. const senders = { logs: (client: PostHogCoreTestClient) => client._sendLogsBatch({ resourceLogs: [] }), metrics: (client: PostHogCoreTestClient) => client._sendMetricsBatch({ resourceMetrics: [] }), + traces: (client: PostHogCoreTestClient) => client._sendTracesBatch({ resourceSpans: [] }), } const cases: [number, string][] = [ diff --git a/packages/core/src/index.ts b/packages/core/src/index.ts index 0ce16dfec6..70c3b8c9c2 100644 --- a/packages/core/src/index.ts +++ b/packages/core/src/index.ts @@ -23,9 +23,8 @@ export { buildResourceAttributes, getOtlpSeverityNumber, getOtlpSeverityText, - toOtlpAnyValue, - toOtlpKeyValueList, } from './logs/logs-utils' +export { toOtlpAnyValue, toOtlpKeyValueList } from './utils/otlp-any-value' export { PostHogLogs } from './logs' export type { BeforeSendLogFn, @@ -68,6 +67,30 @@ export type { Metrics, MetricsConfig, } from './metrics/types' +export { PostHogTraces } from './traces' +export { SyncSpanContextManager } from './traces/context' +export { NOOP_SPAN } from './traces/span' +// The OTLP builders are exported for host adapters that bypass the core flush +// path, mirroring what the logs module exposes for the browser's beacon drain. +export { buildOtlpSpan, buildOtlpTracesPayload, buildTracesResourceAttributes } from './traces/otlp' +export type { + ResolvedTracesConfig, + SendTracesBatchOutcome, + SpanContextManager, + TraceSdkContext, + TracesHost, +} from './traces/types' +// Same barrel convention as logs and metrics for the user-facing tracing types. +export type { + Span, + SpanAttributes, + SpanAttributeValue, + SpanKind, + SpanStatusCode, + SpanTimeInput, + StartSpanOptions, + TracesConfig, +} from './traces/types' export { uuidv7 } from './vendor/uuidv7' export * from './cookie' export * from './posthog-core' diff --git a/packages/core/src/logs/logs-utils.spec.ts b/packages/core/src/logs/logs-utils.spec.ts index 36570cfab5..c869a49e38 100644 --- a/packages/core/src/logs/logs-utils.spec.ts +++ b/packages/core/src/logs/logs-utils.spec.ts @@ -1,13 +1,6 @@ -import type { CaptureLogOptions, LogAttributeValue, LogSeverityLevel } from '@posthog/types' +import type { CaptureLogOptions, LogSeverityLevel } from '@posthog/types' import type { LogSdkContext } from './types' -import { - buildOtlpLogRecord, - buildOtlpLogsPayload, - getOtlpSeverityNumber, - getOtlpSeverityText, - toOtlpAnyValue, - toOtlpKeyValueList, -} from './logs-utils' +import { buildOtlpLogRecord, buildOtlpLogsPayload, getOtlpSeverityNumber, getOtlpSeverityText } from './logs-utils' const browserSdkContext: LogSdkContext = { distinctId: 'user-123', @@ -64,317 +57,6 @@ describe('logs-utils', () => { }) }) - describe('toOtlpAnyValue', () => { - it('converts strings', () => { - expect(toOtlpAnyValue('hello')).toEqual({ stringValue: 'hello' }) - }) - - it('converts integers to decimal strings', () => { - expect(toOtlpAnyValue(42)).toEqual({ intValue: '42' }) - expect(toOtlpAnyValue(0)).toEqual({ intValue: '0' }) - expect(toOtlpAnyValue(-7)).toEqual({ intValue: '-7' }) - }) - - // Spec: outside int64 it is a stringValue, never an intValue. - it('converts integers outside int64 to stringValue', () => { - expect(toOtlpAnyValue(2 ** 63)).toEqual({ stringValue: '9223372036854775808' }) - expect(toOtlpAnyValue(-(2 ** 64))).toEqual({ stringValue: '-18446744073709551616' }) - expect(toOtlpAnyValue(1e21)).toEqual({ stringValue: '1000000000000000000000' }) - }) - - it('logs a debug line when an integer falls outside int64', () => { - const logger = { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn(), critical: jest.fn() } - toOtlpAnyValue(2 ** 63, logger as any) - expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('outside the int64 range')) - }) - - it('keeps int64 min as intValue', () => { - // In range, but `String` renders it 192 below int64 min, so the decimal - // has to come from BigInt. - expect(toOtlpAnyValue(-(2 ** 63))).toEqual({ intValue: '-9223372036854775808' }) - }) - - it('keeps large in-range integers exact', () => { - expect(toOtlpAnyValue(Number.MAX_SAFE_INTEGER)).toEqual({ intValue: '9007199254740991' }) - // The largest double below 2^63 — no double exists between the two. - expect(toOtlpAnyValue(9223372036854774784)).toEqual({ intValue: '9223372036854774784' }) - expect(toOtlpAnyValue(2 ** 62)).toEqual({ intValue: '4611686018427387904' }) - }) - - it('converts floats to doubleValue', () => { - expect(toOtlpAnyValue(3.14)).toEqual({ doubleValue: 3.14 }) - }) - - it('converts booleans', () => { - expect(toOtlpAnyValue(true)).toEqual({ boolValue: true }) - expect(toOtlpAnyValue(false)).toEqual({ boolValue: false }) - }) - - // JSON has no representation for non-finite floats; without explicit - // handling, JSON.stringify silently turns them into `null` and the value - // is lost server-side. - it('converts NaN to stringValue', () => { - expect(toOtlpAnyValue(NaN)).toEqual({ stringValue: 'NaN' }) - }) - - it('converts +Infinity to stringValue', () => { - expect(toOtlpAnyValue(Infinity)).toEqual({ stringValue: 'Infinity' }) - }) - - it('converts -Infinity to stringValue', () => { - expect(toOtlpAnyValue(-Infinity)).toEqual({ stringValue: '-Infinity' }) - }) - - it('converts arrays of strings to arrayValue', () => { - expect(toOtlpAnyValue(['a', 'b'])).toEqual({ - arrayValue: { values: [{ stringValue: 'a' }, { stringValue: 'b' }] }, - }) - }) - - it('converts mixed primitive arrays recursively', () => { - expect(toOtlpAnyValue([1, 'x', true])).toEqual({ - arrayValue: { - values: [{ intValue: '1' }, { stringValue: 'x' }, { boolValue: true }], - }, - }) - }) - - it('converts plain objects to kvlistValue', () => { - expect(toOtlpAnyValue({ a: 1, b: 'two' })).toEqual({ - kvlistValue: { - values: [ - { key: 'a', value: { intValue: '1' } }, - { key: 'b', value: { stringValue: 'two' } }, - ], - }, - }) - }) - - it('converts nested objects recursively', () => { - expect(toOtlpAnyValue({ outer: { inner: 1 } })).toEqual({ - kvlistValue: { - values: [ - { - key: 'outer', - value: { kvlistValue: { values: [{ key: 'inner', value: { intValue: '1' } }] } }, - }, - ], - }, - }) - }) - - it('drops null and undefined keys inside objects', () => { - expect(toOtlpAnyValue({ kept: 1, gone: null, alsoGone: undefined })).toEqual({ - kvlistValue: { values: [{ key: 'kept', value: { intValue: '1' } }] }, - }) - }) - - // Not in LogAttributeValue, but reachable at runtime from untyped callers. - it('encodes Dates as ISO strings', () => { - expect(toOtlpAnyValue(new Date('2026-08-20T10:00:00.000Z') as unknown as LogAttributeValue)).toEqual({ - stringValue: '2026-08-20T10:00:00.000Z', - }) - }) - - it('marks circular references instead of recursing', () => { - const cyclic: Record = { name: 'root' } - cyclic.self = cyclic - expect(toOtlpAnyValue(cyclic)).toEqual({ - kvlistValue: { - values: [ - { key: 'name', value: { stringValue: 'root' } }, - { key: 'self', value: { stringValue: '[Circular]' } }, - ], - }, - }) - }) - - // An escaping error would surface in the caller's application code. - it('does not throw on an object nested past the depth cap', () => { - let deep: Record = { end: true } - for (let i = 0; i < 25000; i++) { - deep = { next: deep } - } - expect(() => toOtlpAnyValue(deep)).not.toThrow() - }) - - it('truncates at exactly 20 levels instead of recursing', () => { - let deep: Record = { end: true } - for (let i = 0; i < 25; i++) { - deep = { next: deep } - } - const encoded = JSON.stringify(toOtlpAnyValue(deep)) - expect(encoded).toContain('[Truncated]') - expect(encoded.split('"next"').length - 1).toBe(20) - }) - - it('marks a throwing getter without losing the rest of the object', () => { - const attrs = { - ok: 1, - get bad(): number { - throw new Error('getter blew up') - }, - } - expect(() => toOtlpKeyValueList(attrs)).not.toThrow() - expect(toOtlpKeyValueList(attrs)).toEqual([ - { key: 'ok', value: { intValue: '1' } }, - { key: 'bad', value: { stringValue: '[Unserializable]' } }, - ]) - }) - - // for...in walks the prototype chain once own keys are exhausted. - it('ignores inherited enumerable properties', () => { - const inherited: Record = Object.create({ fromPrototype: 'leaked' }) - inherited.own = 1 - expect(toOtlpAnyValue(inherited)).toEqual({ - kvlistValue: { values: [{ key: 'own', value: { intValue: '1' } }] }, - }) - }) - - // `String(fn)` would put the function's source text on the wire. - it('marks function and symbol values instead of stringifying them', () => { - expect(toOtlpAnyValue({ handler: () => 1, retries: 2 } as unknown as LogAttributeValue)).toEqual({ - kvlistValue: { - values: [ - { key: 'handler', value: { stringValue: '[Function]' } }, - { key: 'retries', value: { intValue: '2' } }, - ], - }, - }) - expect(toOtlpAnyValue({ sym: Symbol('x') } as unknown as LogAttributeValue)).toEqual({ - kvlistValue: { values: [{ key: 'sym', value: { stringValue: 'Symbol(x)' } }] }, - }) - }) - - // dayjs, Decimal, ORM documents. - it('honours toJSON', () => { - const wrapped = { toJSON: () => ({ amount: 5 }) } - expect(toOtlpAnyValue(wrapped as unknown as LogAttributeValue)).toEqual({ - kvlistValue: { values: [{ key: 'amount', value: { intValue: '5' } }] }, - }) - }) - - it('falls back to the plain walk when toJSON throws', () => { - const wrapped = { - kept: 1, - toJSON: () => { - throw new Error('nope') - }, - } - expect(toOtlpAnyValue(wrapped as unknown as LogAttributeValue)).toEqual({ - kvlistValue: { - values: [ - { key: 'kept', value: { intValue: '1' } }, - { key: 'toJSON', value: { stringValue: '[Function]' } }, - ], - }, - }) - }) - - // A toJSON returning its own object is a cycle like any other. - it('marks a cycle that runs through toJSON', () => { - const cyclic: Record = {} - cyclic.toJSON = () => ({ inner: cyclic }) - expect(toOtlpAnyValue(cyclic)).toEqual({ - kvlistValue: { values: [{ key: 'inner', value: { stringValue: '[Circular]' } }] }, - }) - }) - - // Both `null` and `{}` here are rejected for the whole request; iOS and - // Android drop them too. - it('drops holes and nullish elements from arrays', () => { - // eslint-disable-next-line no-sparse-arrays - expect(toOtlpAnyValue([1, , 3])).toEqual({ - arrayValue: { values: [{ intValue: '1' }, { intValue: '3' }] }, - }) - expect(toOtlpAnyValue([1, null, undefined, 3])).toEqual({ - arrayValue: { values: [{ intValue: '1' }, { intValue: '3' }] }, - }) - }) - - it('stops encoding array items once the node budget is spent', () => { - const row: Record = {} - for (let i = 0; i < 20; i++) { - row[`k${i}`] = i - } - const wide = Array.from({ length: 1000 }, () => ({ ...row })) - const values = toOtlpAnyValue(wide).arrayValue!.values - expect(values[values.length - 1]).toEqual({ stringValue: '[Truncated]' }) - // One marker, not one per unencodable item. - expect(values.filter((v) => v.stringValue === '[Truncated]')).toHaveLength(1) - }) - - it('caps a shared object graph instead of expanding it', () => { - let graph: Record = { leaf: true } - for (let i = 0; i < 20; i++) { - graph = { a: graph, b: graph } - } - const encoded = JSON.stringify(toOtlpAnyValue(graph)) - expect(encoded).toContain('[Truncated]') - expect(encoded.length).toBeLessThan(1_000_000) - }) - - it('caps a very wide object without inventing an attribute key', () => { - const wide: Record = {} - for (let i = 0; i < 5000; i++) { - wide[`k${i}`] = i - } - const logger = { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn(), critical: jest.fn() } - const values = toOtlpAnyValue(wide, logger as any).kvlistValue!.values - expect(values).toHaveLength(1000) - expect(values.every((v) => v.key.startsWith('k'))).toBe(true) - expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('truncated')) - }) - - // Why the encoder does not delegate to toJsonSafeValue: that maps them to null. - it('keeps non-finite floats as strings inside nested objects', () => { - expect(toOtlpAnyValue({ nested: { ratio: NaN } })).toEqual({ - kvlistValue: { - values: [ - { - key: 'nested', - value: { kvlistValue: { values: [{ key: 'ratio', value: { stringValue: 'NaN' } }] } }, - }, - ], - }, - }) - }) - - // A lone surrogate survives JSON.stringify as a \uD800 escape, which the - // server rejects for the whole request. - it('replaces unpaired surrogates in values and keys', () => { - expect(toOtlpAnyValue('ok\ud83d')).toEqual({ stringValue: 'ok\ufffd' }) - expect(toOtlpAnyValue({ nested: 'ok\ud83d' })).toEqual({ - kvlistValue: { values: [{ key: 'nested', value: { stringValue: 'ok\ufffd' } }] }, - }) - expect(toOtlpKeyValueList({ 'key\ud83d': 1 })).toEqual([{ key: 'key\ufffd', value: { intValue: '1' } }]) - }) - - it('encodes empty containers with an explicit values array', () => { - expect(toOtlpAnyValue({})).toEqual({ kvlistValue: { values: [] } }) - expect(toOtlpAnyValue([])).toEqual({ arrayValue: { values: [] } }) - }) - - it('keeps a Date whose toISOString is overridden out of the wire format', () => { - const broken = new Date('2026-08-20T10:00:00.000Z') - - ;(broken as any).toISOString = () => ({}) - expect(typeof toOtlpAnyValue(broken as unknown as LogAttributeValue).stringValue).toBe('string') - }) - - it('encodes sibling references to one object twice, not as circular', () => { - const shared = { id: 1 } - expect(toOtlpAnyValue({ a: shared, b: shared })).toEqual({ - kvlistValue: { - values: [ - { key: 'a', value: { kvlistValue: { values: [{ key: 'id', value: { intValue: '1' } }] } } }, - { key: 'b', value: { kvlistValue: { values: [{ key: 'id', value: { intValue: '1' } }] } } }, - ], - }, - }) - }) - }) - describe('buildOtlpLogRecord attribute reads', () => { // Reading `options.attributes` happens before the encoder's per-key guard. it('marks an attribute whose getter throws without dropping the record', () => { @@ -425,36 +107,6 @@ describe('logs-utils', () => { }) }) - describe('toOtlpKeyValueList', () => { - it('converts a record to key-value list', () => { - expect( - toOtlpKeyValueList({ - name: 'test', - count: 5, - active: true, - }) - ).toEqual([ - { key: 'name', value: { stringValue: 'test' } }, - { key: 'count', value: { intValue: '5' } }, - { key: 'active', value: { boolValue: true } }, - ]) - }) - - it('handles empty record', () => { - expect(toOtlpKeyValueList({})).toEqual([]) - }) - - it('skips null and undefined values', () => { - expect( - toOtlpKeyValueList({ - kept: 'yes', - nullish: null, - missing: undefined, - }) - ).toEqual([{ key: 'kept', value: { stringValue: 'yes' } }]) - }) - }) - describe('buildOtlpLogRecord', () => { it('builds a minimal log record', () => { const record = buildOtlpLogRecord({ body: 'hello world' }, minimalSdkContext) diff --git a/packages/core/src/logs/logs-utils.ts b/packages/core/src/logs/logs-utils.ts index 5e3789861e..d94d556c82 100644 --- a/packages/core/src/logs/logs-utils.ts +++ b/packages/core/src/logs/logs-utils.ts @@ -2,8 +2,6 @@ import type { CaptureLogOptions, LogAttributeValue, LogSeverityLevel, - OtlpAnyValue, - OtlpKeyValue, OtlpLogRecord, OtlpLogsPayload, OtlpSeverityEntry, @@ -11,17 +9,9 @@ import type { } from '@posthog/types' import type { Logger } from '../types' import type { LogSdkContext, ResolvedPostHogLogsConfig } from './types' -import { isArray, isBoolean, isNull, isNullish, isUndefined } from '../utils' -import { - CIRCULAR_VALUE, - FUNCTION_VALUE, - MAX_JSON_SAFE_VALUE_DEPTH, - MAX_JSON_SAFE_VALUE_ITEMS, - MAX_JSON_SAFE_VALUE_NODES, - sanitizeString, - TRUNCATED_VALUE, - UNSERIALIZABLE_VALUE, -} from '../utils/json-utils' +import { isNullish, isUndefined } from '../utils' +import { sanitizeString, UNSERIALIZABLE_VALUE } from '../utils/json-utils' +import { toOtlpKeyValueList } from '../utils/otlp-any-value' // ============================================================================ // Severity mapping @@ -46,200 +36,6 @@ export function getOtlpSeverityNumber(level: LogSeverityLevel): number { return (OTLP_SEVERITY_MAP[level] || DEFAULT_OTLP_SEVERITY).number } -// ============================================================================ -// OTLP AnyValue conversion -// ============================================================================ - -// 2^63 — one past int64 max. -const INT64_RANGE_LIMIT = 9223372036854775808 - -const propertyIsEnumerable = Object.prototype.propertyIsEnumerable - -interface EncodeState { - /** Containers on the current path, so a back-reference becomes a marker. */ - ancestors: WeakSet - remainingNodes: number -} - -function newState(): EncodeState { - return { ancestors: new WeakSet(), remainingNodes: MAX_JSON_SAFE_VALUE_NODES } -} - -export function toOtlpAnyValue(value: LogAttributeValue, logger?: Logger): OtlpAnyValue { - try { - return encodeAnyValue(value, logger, newState(), 0) - } catch { - // Runs inside `captureLog` and the metrics flush: an error escaping here - // surfaces in the caller's own code. - return { stringValue: UNSERIALIZABLE_VALUE } - } -} - -export function toOtlpKeyValueList(attrs: Record, logger?: Logger): OtlpKeyValue[] { - try { - return encodeKeyValueList(attrs, logger, newState(), 0) - } catch { - return [] - } -} - -function encodeAnyValue( - value: LogAttributeValue, - logger: Logger | undefined, - state: EncodeState, - depth: number -): OtlpAnyValue { - if (state.remainingNodes <= 0) { - return { stringValue: TRUNCATED_VALUE } - } - state.remainingNodes-- - - if (isBoolean(value)) { - return { boolValue: value } - } - // typeof, not core's isNumber, which excludes NaN — proto3 JSON distinguishes - // a non-finite float from an ordinary string. - if (typeof value === 'number') { - if (!Number.isFinite(value)) { - return { stringValue: String(value) } - } - if (Number.isInteger(value)) { - if (Number.isSafeInteger(value)) { - return { intValue: String(value) } - } - // Past MAX_SAFE_INTEGER only BigInt gives the double's exact decimal: - // `String(-(2**63))` lands 192 below int64 min, outside the field it is - // about to be parsed into. Without BigInt the value rides as a string, - // which is never range-checked. - if (typeof BigInt === 'undefined') { - return { stringValue: String(value) } - } - const decimal = BigInt(value).toString() - if (value >= INT64_RANGE_LIMIT || value < -INT64_RANGE_LIMIT) { - // An out-of-range intValue 400s the whole logs request; on the metrics - // path it is swallowed server-side and the metric just disappears. - logger?.debug(`Attribute ${decimal} is outside the int64 range; encoding it as a string`) - return { stringValue: decimal } - } - return { intValue: decimal } - } - return { doubleValue: value } - } - if (typeof value === 'string') { - return { stringValue: sanitizeString(value) } - } - // `String(value)` would put a function's source text on the wire. - if (typeof value === 'function') { - return { stringValue: FUNCTION_VALUE } - } - if (typeof value === 'symbol') { - return { stringValue: String(value) } - } - if (typeof value === 'object' && value !== null) { - if (state.ancestors.has(value)) { - return { stringValue: CIRCULAR_VALUE } - } - if (depth >= MAX_JSON_SAFE_VALUE_DEPTH) { - return { stringValue: TRUNCATED_VALUE } - } - if (value instanceof Date) { - const time = value.getTime() - const iso = Number.isFinite(time) ? value.toISOString() : String(value) - // An overridden toISOString can return a non-string, which the server - // refuses for the whole request. - return { stringValue: typeof iso === 'string' ? sanitizeString(iso) : String(iso) } - } - // Registered before the toJSON probe: a toJSON returning a structure that - // references its own object is a cycle like any other. - state.ancestors.add(value) - try { - // The representation a value defines for itself — dayjs, Decimal, an ORM - // document, and a cross-realm Date that fails the `instanceof` above. - try { - const toJSON = (value as { toJSON?: unknown }).toJSON - if (typeof toJSON === 'function') { - return encodeAnyValue(toJSON.call(value) as LogAttributeValue, logger, state, depth + 1) - } - } catch { - // A throwing toJSON falls through to the plain walk. - } - if (isArray(value)) { - return { arrayValue: { values: encodeArrayValues(value, logger, state, depth + 1) } } - } - return { - kvlistValue: { - values: encodeKeyValueList(value as Record, logger, state, depth + 1), - }, - } - } finally { - // Siblings that reference the same object are duplication, not a cycle. - state.ancestors.delete(value) - } - } - return { stringValue: sanitizeString(String(value)) } -} - -function encodeArrayValues( - values: unknown[], - logger: Logger | undefined, - state: EncodeState, - depth: number -): OtlpAnyValue[] { - const result: OtlpAnyValue[] = [] - const itemCount = Math.min(values.length, MAX_JSON_SAFE_VALUE_ITEMS) - let index = 0 - for (; index < itemCount && state.remainingNodes > 0; index++) { - try { - const element = index in values ? values[index] : undefined - // Dropped, as iOS and Android do: proto3 JSON has no null AnyValue, and - // both `null` and `{}` here are rejected for the whole request. - if (isNullish(element)) { - continue - } - result.push(encodeAnyValue(element as LogAttributeValue, logger, state, depth)) - } catch { - result.push({ stringValue: UNSERIALIZABLE_VALUE }) - } - } - if (values.length > index) { - result.push({ stringValue: TRUNCATED_VALUE }) - } - return result -} - -function encodeKeyValueList( - attrs: Record, - logger: Logger | undefined, - state: EncodeState, - depth: number -): OtlpKeyValue[] { - const result: OtlpKeyValue[] = [] - for (const key in attrs) { - // for...in walks the prototype chain once own keys are exhausted. Skipped - // rather than broken out of: a proxy can yield keys in any order. - if (!propertyIsEnumerable.call(attrs, key)) { - continue - } - if (result.length >= MAX_JSON_SAFE_VALUE_ITEMS || state.remainingNodes <= 0) { - // Reported rather than written into the attributes: a synthetic key would - // land in the user's own namespace and could collide with a real one. - logger?.debug('Attributes truncated: the value exceeds the OTLP encoder budget') - break - } - try { - const value = attrs[key] - if (isNull(value) || isUndefined(value)) { - continue - } - result.push({ key: sanitizeString(key), value: encodeAnyValue(value, logger, state, depth) }) - } catch { - // A getter that throws costs its own key, not the whole record. - result.push({ key: sanitizeString(key), value: { stringValue: UNSERIALIZABLE_VALUE } }) - } - } - return result -} - // ============================================================================ // OTLP LogRecord construction // ============================================================================ diff --git a/packages/core/src/metrics/index.ts b/packages/core/src/metrics/index.ts index d88c595dc2..cb86a0336e 100644 --- a/packages/core/src/metrics/index.ts +++ b/packages/core/src/metrics/index.ts @@ -10,7 +10,7 @@ import type { } from '@posthog/types' import type { Logger } from '../types' import { isArray, safeSetTimeout } from '../utils' -import { toOtlpKeyValueList } from '../logs/logs-utils' +import { toOtlpKeyValueList } from '../utils/otlp-any-value' import { DEFAULT_HISTOGRAM_BOUNDS, bucketIndexFor, diff --git a/packages/core/src/metrics/metrics-utils.ts b/packages/core/src/metrics/metrics-utils.ts index 197455e7c0..4fb534bbba 100644 --- a/packages/core/src/metrics/metrics-utils.ts +++ b/packages/core/src/metrics/metrics-utils.ts @@ -1,5 +1,5 @@ import type { MetricAttributeValue, OtlpMetric, OtlpMetricsPayload } from '@posthog/types' -import { toOtlpKeyValueList } from '../logs/logs-utils' +import { toOtlpKeyValueList } from '../utils/otlp-any-value' import type { ResolvedPostHogMetricsConfig } from './types' /** diff --git a/packages/core/src/posthog-core-stateless.ts b/packages/core/src/posthog-core-stateless.ts index 36d9b95385..eff851e9fa 100644 --- a/packages/core/src/posthog-core-stateless.ts +++ b/packages/core/src/posthog-core-stateless.ts @@ -1,5 +1,6 @@ -import type { OtlpLogsPayload, OtlpMetricsPayload } from '@posthog/types' +import type { OtlpLogsPayload, OtlpMetricsPayload, OtlpTracesPayload } from '@posthog/types' import type { SendMetricsBatchOutcome } from './metrics/types' +import type { SendTracesBatchOutcome } from './traces/types' import { SimpleEventEmitter } from './eventemitter' import { getFeatureFlagValue, minimizeFlagCalledEventProperties, normalizeFlagsResponse } from './featureFlagUtils' import { gzipCompress, isGzipSupported } from './gzip' @@ -239,8 +240,8 @@ export type SendLogsBatchOutcome = /** * Each signal keeps its own exported outcome type because each belongs to a - * separate host contract. The wrappers return this value directly, so one - * drifting out of shape fails to compile. + * separate host contract. The wrappers return this value directly, so any of + * the three drifting out of shape fails to compile. */ type SendOtlpBatchOutcome = | { kind: 'ok' } @@ -1643,9 +1644,9 @@ export abstract class PostHogCoreStateless { } /** - * Shared implementation behind the OTLP senders, which differ only in path. - * Returns a tagged outcome instead of throwing so the queue owners don't - * have to know the core's error class hierarchy. + * Shared implementation behind the three OTLP senders, which differ only in + * path and auth style. Returns a tagged outcome instead of throwing so the + * queue owners don't have to know the core's error class hierarchy. * * Exhausted 408/429/5xx stay `retry-later`, unlike the events `_flush()` * which drops anything that isn't a network error: every OTLP queue is @@ -1654,17 +1655,22 @@ export abstract class PostHogCoreStateless { */ private async _sendOtlpBatch({ path, + auth, payload, }: { - path: 'logs' | 'metrics' - payload: OtlpLogsPayload | OtlpMetricsPayload + path: 'logs' | 'metrics' | 'traces' + auth: 'query-token' | 'bearer' + payload: OtlpLogsPayload | OtlpMetricsPayload | OtlpTracesPayload }): Promise { if (this.disabled) { return { kind: 'fatal', error: new Error('The client is disabled') } } const serialized = JSON.stringify(payload) - const url = `${this.host}/i/v1/${path}?token=${encodeURIComponent(this.apiKey)}` + const url = + auth === 'bearer' + ? `${this.host}/i/v1/${path}` + : `${this.host}/i/v1/${path}?token=${encodeURIComponent(this.apiKey)}` const gzippedPayload = !this.disableCompression ? await this.compressPayload(serialized) : null const fetchOptions: PostHogFetchOptions = { @@ -1672,6 +1678,7 @@ export abstract class PostHogCoreStateless { headers: { ...this.getCustomHeaders(), 'Content-Type': 'application/json', + ...(auth === 'bearer' && { Authorization: `Bearer ${this.apiKey}` }), ...(gzippedPayload !== null && { 'Content-Encoding': 'gzip' }), }, body: gzippedPayload || serialized, @@ -1704,11 +1711,23 @@ export abstract class PostHogCoreStateless { } async _sendLogsBatch(payload: OtlpLogsPayload): Promise { - return this._sendOtlpBatch({ path: 'logs', payload }) + return this._sendOtlpBatch({ path: 'logs', auth: 'query-token', payload }) } async _sendMetricsBatch(payload: OtlpMetricsPayload): Promise { - return this._sendOtlpBatch({ path: 'metrics', payload }) + return this._sendOtlpBatch({ path: 'metrics', auth: 'query-token', payload }) + } + + /** + * The `TracesHost._sendTracesBatch` implementation, so `PostHogTraces` can + * use any core-based SDK as its host. + * + * Authenticates with `Authorization: Bearer` rather than the `?token=` query + * parameter the logs and metrics senders use: it's the service's primary auth + * path, and server runtimes have no CORS preflight to avoid. + */ + async _sendTracesBatch(payload: OtlpTracesPayload): Promise { + return this._sendOtlpBatch({ path: 'traces', auth: 'bearer', payload }) } private fetchWithRetry( diff --git a/packages/core/src/traces/context.ts b/packages/core/src/traces/context.ts new file mode 100644 index 0000000000..347306d6e8 --- /dev/null +++ b/packages/core/src/traces/context.ts @@ -0,0 +1,33 @@ +import type { Span } from '@posthog/types' +import type { SpanContextManager } from './types' + +/** + * Synchronous active-span tracking. + * + * Restores the previous active span when the callback returns, which for an + * async callback means when it returns its promise — not when that promise + * settles. Spans started after an `await` inside the callback therefore won't + * see it as active. + * + * This is the browser's documented limitation and the fallback for any runtime + * without an ambient async context primitive. Node injects an + * `AsyncLocalStorage`-backed manager instead, which carries activation across + * `await`. Either way, the explicit `parent` option is the escape hatch. + */ +export class SyncSpanContextManager implements SpanContextManager { + private _active: Span | undefined + + active(): Span | undefined { + return this._active + } + + with(span: Span, fn: () => T): T { + const previous = this._active + this._active = span + try { + return fn() + } finally { + this._active = previous + } + } +} diff --git a/packages/core/src/traces/ids.spec.ts b/packages/core/src/traces/ids.spec.ts new file mode 100644 index 0000000000..bbc3833b59 --- /dev/null +++ b/packages/core/src/traces/ids.spec.ts @@ -0,0 +1,115 @@ +import { getRandomBytes, isValidSpanId, isValidTraceId, newSpanId, newTraceId } from './ids' + +describe('trace and span ids', () => { + describe('newTraceId', () => { + it('is 32 lowercase hex characters', () => { + for (let i = 0; i < 50; i++) { + expect(newTraceId()).toMatch(/^[0-9a-f]{32}$/) + } + }) + + it('is never all zeros', () => { + for (let i = 0; i < 50; i++) { + expect(newTraceId()).not.toBe('0'.repeat(32)) + } + }) + + it('does not repeat', () => { + const ids = new Set(Array.from({ length: 200 }, newTraceId)) + expect(ids.size).toBe(200) + }) + }) + + describe('newSpanId', () => { + it('is 16 lowercase hex characters', () => { + for (let i = 0; i < 50; i++) { + expect(newSpanId()).toMatch(/^[0-9a-f]{16}$/) + } + }) + + it('does not repeat', () => { + const ids = new Set(Array.from({ length: 200 }, newSpanId)) + expect(ids.size).toBe(200) + }) + }) + + describe('getRandomBytes', () => { + it('returns the requested length', () => { + expect(getRandomBytes(8)).toHaveLength(8) + expect(getRandomBytes(16)).toHaveLength(16) + }) + + it('falls back to Math.random when crypto is unavailable', () => { + const original = Object.getOwnPropertyDescriptor(globalThis, 'crypto') + // React Native has no global crypto without a polyfill — the fallback path + // is what keeps span ids working there. + Object.defineProperty(globalThis, 'crypto', { value: undefined, configurable: true }) + try { + expect(newTraceId()).toMatch(/^[0-9a-f]{32}$/) + expect(newSpanId()).toMatch(/^[0-9a-f]{16}$/) + } finally { + if (original) { + Object.defineProperty(globalThis, 'crypto', original) + } + } + }) + + it('falls back when getRandomValues throws', () => { + const original = Object.getOwnPropertyDescriptor(globalThis, 'crypto') + Object.defineProperty(globalThis, 'crypto', { + value: { + getRandomValues: () => { + throw new Error('not allowed') + }, + }, + configurable: true, + }) + try { + expect(newTraceId()).toMatch(/^[0-9a-f]{32}$/) + } finally { + if (original) { + Object.defineProperty(globalThis, 'crypto', original) + } + } + }) + + it('never emits an all-zero id even when the random source is broken', () => { + const original = Object.getOwnPropertyDescriptor(globalThis, 'crypto') + Object.defineProperty(globalThis, 'crypto', { + value: { getRandomValues: (array: Uint8Array) => array.fill(0) }, + configurable: true, + }) + try { + // The server zeroes ids it can't use, so an all-zero id would be stored + // and silently orphaned rather than rejected. + expect(newTraceId()).not.toBe('0'.repeat(32)) + expect(newSpanId()).not.toBe('0'.repeat(16)) + } finally { + if (original) { + Object.defineProperty(globalThis, 'crypto', original) + } + } + }) + }) + + describe('validation', () => { + it.each([ + ['a valid trace id', '4bf92f3577b34da6a3ce929d0e0e4736', true], + ['an all-zero trace id', '0'.repeat(32), false], + ['a short trace id', 'abc', false], + ['uppercase hex', '4BF92F3577B34DA6A3CE929D0E0E4736', false], + ['a non-hex string', 'zzf92f3577b34da6a3ce929d0e0e4736', false], + ['a non-string', 12345, false], + ])('isValidTraceId rejects/accepts %s', (_name, value, expected) => { + expect(isValidTraceId(value)).toBe(expected) + }) + + it.each([ + ['a valid span id', '00f067aa0ba902b7', true], + ['an all-zero span id', '0'.repeat(16), false], + ['a trace-length id', '4bf92f3577b34da6a3ce929d0e0e4736', false], + ])('isValidSpanId rejects/accepts %s', (_name, value, expected) => { + expect(isValidSpanId(value)).toBe(expected) + }) + }) +}) diff --git a/packages/core/src/traces/ids.ts b/packages/core/src/traces/ids.ts new file mode 100644 index 0000000000..39084665b1 --- /dev/null +++ b/packages/core/src/traces/ids.ts @@ -0,0 +1,80 @@ +// W3C Trace Context identifier generation. +// +// Trace ids are 16 bytes, span ids 8, both lowercase hex on the JSON wire. The +// ingestion service *zeroes* ids that aren't exactly the right length rather +// than rejecting them, which silently orphans the span — so length is +// load-bearing and every id is validated before it goes out. + +const TRACE_ID_BYTES = 16 +const SPAN_ID_BYTES = 8 + +const TRACE_ID_HEX = TRACE_ID_BYTES * 2 +const SPAN_ID_HEX = SPAN_ID_BYTES * 2 + +const INVALID_TRACE_ID = '0'.repeat(TRACE_ID_HEX) +const INVALID_SPAN_ID = '0'.repeat(SPAN_ID_HEX) + +const HEX_RE = /^[0-9a-f]+$/ + +type CryptoLike = { getRandomValues?: (array: Uint8Array) => Uint8Array } + +/** + * Random bytes from the platform's CSPRNG, falling back to `Math.random`. + * + * The fallback exists for React Native, which has no global `crypto` without a + * polyfill — the same reason core's vendored uuidv7 takes that path. Trace ids + * only need collision resistance, not unpredictability, so the fallback is + * acceptable; browsers, Node and edge runtimes all take the CSPRNG path. + */ +export function getRandomBytes(byteLength: number): Uint8Array { + const bytes = new Uint8Array(byteLength) + const cryptoLike = (globalThis as { crypto?: CryptoLike }).crypto + if (cryptoLike && typeof cryptoLike.getRandomValues === 'function') { + try { + cryptoLike.getRandomValues(bytes) + return bytes + } catch { + // Fall through to Math.random below. + } + } + for (let i = 0; i < byteLength; i++) { + bytes[i] = Math.floor(Math.random() * 256) + } + return bytes +} + +function bytesToHex(bytes: Uint8Array): string { + let hex = '' + for (let i = 0; i < bytes.length; i++) { + hex += bytes[i].toString(16).padStart(2, '0') + } + return hex +} + +function randomHexId(byteLength: number): string { + const hex = bytesToHex(getRandomBytes(byteLength)) + // An all-zero id is invalid per W3C, and the server treats one as absent + // rather than rejecting it — the span would be stored and silently orphaned. + // Unreachable from a real random source; this only guards a broken one. + return /[^0]/.test(hex) ? hex : hex.slice(0, -1) + '1' +} + +export function newTraceId(): string { + return randomHexId(TRACE_ID_BYTES) +} + +export function newSpanId(): string { + return randomHexId(SPAN_ID_BYTES) +} + +function isValidHexId(value: unknown, length: number, invalid: string): value is string { + return typeof value === 'string' && value.length === length && value !== invalid && HEX_RE.test(value) +} + +export function isValidTraceId(value: unknown): value is string { + return isValidHexId(value, TRACE_ID_HEX, INVALID_TRACE_ID) +} + +export function isValidSpanId(value: unknown): value is string { + return isValidHexId(value, SPAN_ID_HEX, INVALID_SPAN_ID) +} diff --git a/packages/core/src/traces/index.spec.ts b/packages/core/src/traces/index.spec.ts new file mode 100644 index 0000000000..da71d29eb8 --- /dev/null +++ b/packages/core/src/traces/index.spec.ts @@ -0,0 +1,825 @@ +import { PostHogTraces } from './index' +import { SyncSpanContextManager } from './context' +import { NOOP_SPAN } from './span' +import type { + OtlpSpan, + OtlpTracesPayload, + ResolvedTracesConfig, + SendTracesBatchOutcome, + TraceSdkContext, +} from './types' +import type { Logger } from '../types' +import { createMockLogger } from '@/testing' + +const TRACE_ID = '4bf92f3577b34da6a3ce929d0e0e4736' +const REMOTE_SPAN_ID = '00f067aa0ba902b7' + +const resolveForTest = (partial?: Partial): ResolvedTracesConfig => ({ + flushIntervalMs: 5000, + maxExportBatchSize: 512, + maxQueueSize: 2048, + ...partial, +}) + +const createMockInstance = (overrides: Record = {}): any => ({ + isDisabled: false, + optedOut: false, + getLibraryId: jest.fn(() => 'posthog-core-tests'), + getLibraryVersion: jest.fn(() => '0.0.0-test'), + _sendTracesBatch: jest.fn((): Promise => Promise.resolve({ kind: 'ok' })), + ...overrides, +}) + +describe('PostHogTraces', () => { + let mockInstance: any + let logger: Logger + let context: TraceSdkContext + + const createTraces = (config?: Partial, instance?: any): PostHogTraces => + new PostHogTraces( + instance ?? mockInstance, + resolveForTest(config), + logger, + () => context, + new SyncSpanContextManager() + ) + + const sentPayloads = (instance?: any): OtlpTracesPayload[] => + (instance ?? mockInstance)._sendTracesBatch.mock.calls.map((c: any[]) => c[0]) + + const sentSpans = (instance?: any): OtlpSpan[] => + sentPayloads(instance).flatMap((p) => p.resourceSpans[0].scopeSpans[0].spans) + + beforeEach(() => { + mockInstance = createMockInstance() + logger = createMockLogger() + context = {} + }) + + describe('startSpan', () => { + it('enqueues exactly one record per span', async () => { + const traces = createTraces() + traces.startSpan('checkout').end() + await traces.flush() + + expect(sentSpans()).toHaveLength(1) + expect(sentSpans()[0].name).toBe('checkout') + }) + + it('gives a root span a fresh trace id and no parent', async () => { + const traces = createTraces() + traces.startSpan('root').end() + await traces.flush() + + const [span] = sentSpans() + expect(span.traceId).toMatch(/^[0-9a-f]{32}$/) + expect(span.spanId).toMatch(/^[0-9a-f]{16}$/) + expect(span.parentSpanId).toBeUndefined() + }) + + it('does not activate the span it returns', () => { + const traces = createTraces() + const manual = traces.startSpan('manual') + expect(traces.getActiveSpan()).toBeNull() + manual.end() + }) + + it('parents a child to an explicit span handle', async () => { + const traces = createTraces() + const parent = traces.startSpan('parent') + const child = traces.startSpan('child', { parent }) + child.end() + parent.end() + await traces.flush() + + const [childSpan, parentSpan] = sentSpans() + expect(childSpan.traceId).toBe(parentSpan.traceId) + expect(childSpan.parentSpanId).toBe(parentSpan.spanId) + }) + + it('defaults kind to internal and honours an explicit kind', async () => { + const traces = createTraces() + traces.startSpan('a').end() + traces.startSpan('b', { kind: 'server' }).end() + await traces.flush() + + expect(sentSpans().map((s) => s.kind)).toEqual([1, 2]) + }) + + it('returns an inert handle when the SDK is disabled', async () => { + const traces = createTraces({}, createMockInstance({ isDisabled: true })) + const span = traces.startSpan('checkout') + span.end() + + expect(span).toBe(NOOP_SPAN) + expect(span.traceparent()).toBeNull() + }) + + it('returns an inert handle when the user has opted out', () => { + const traces = createTraces({}, createMockInstance({ optedOut: true })) + expect(traces.startSpan('checkout')).toBe(NOOP_SPAN) + }) + + it('makes a child of a no-op handle a no-op rather than an orphan', () => { + const traces = createTraces() + expect(traces.startSpan('child', { parent: NOOP_SPAN })).toBe(NOOP_SPAN) + }) + }) + + describe('startTime', () => { + it('backdates the span to a supplied start', async () => { + const traces = createTraces() + const start = Date.now() - 60_000 + traces.startSpan('backdated', { startTime: start }).end() + await traces.flush() + + expect(sentSpans()[0].startTimeUnixNano).toBe(`${start}000000`) + }) + + it('accepts a Date', async () => { + const traces = createTraces() + const start = new Date(Date.now() - 5_000) + traces.startSpan('backdated', { startTime: start }).end() + await traces.flush() + + expect(sentSpans()[0].startTimeUnixNano).toBe(`${start.getTime()}000000`) + }) + + it('falls back to now for an unusable start, keeping the record well formed', async () => { + const traces = createTraces() + traces.startSpan('bad', { startTime: Number.NaN }).end() + await traces.flush() + + const [span] = sentSpans() + expect(span.startTimeUnixNano).toMatch(/^\d+$/) + expect(Number(span.endTimeUnixNano)).toBeGreaterThanOrEqual(Number(span.startTimeUnixNano)) + }) + + it('warns when a start is old enough for the server to clamp it', async () => { + const traces = createTraces() + traces.startSpan('stale', { startTime: Date.now() - 48 * 60 * 60 * 1000 }).end() + await traces.flush() + + expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('24 hours')) + expect(sentSpans()).toHaveLength(1) + }) + }) + + describe('trace continuation', () => { + it('continues a remote trace from a traceparent string', async () => { + const traces = createTraces() + traces.startSpan('handler', { parent: `00-${TRACE_ID}-${REMOTE_SPAN_ID}-01` }).end() + await traces.flush() + + const [span] = sentSpans() + expect(span.traceId).toBe(TRACE_ID) + expect(span.parentSpanId).toBe(REMOTE_SPAN_ID) + }) + + it('continues a trace the caller sampled out', async () => { + const traces = createTraces() + traces.startSpan('handler', { parent: `00-${TRACE_ID}-${REMOTE_SPAN_ID}-00` }).end() + await traces.flush() + + expect(sentSpans()[0].traceId).toBe(TRACE_ID) + }) + + it('preserves tracestate opaquely and passes it to children', async () => { + const traces = createTraces() + const parent = traces.startSpan('handler', { + parent: `00-${TRACE_ID}-${REMOTE_SPAN_ID}-01`, + tracestate: 'vendor=abc', + }) + const child = traces.startSpan('inner', { parent }) + expect(parent.tracestate()).toBe('vendor=abc') + + child.end() + parent.end() + await traces.flush() + + expect(sentSpans().map((s) => s.traceState)).toEqual(['vendor=abc', 'vendor=abc']) + }) + + it('starts a fresh root on a malformed traceparent without throwing', async () => { + const traces = createTraces() + expect(() => traces.startSpan('handler', { parent: 'garbage' }).end()).not.toThrow() + await traces.flush() + + const [span] = sentSpans() + expect(span.traceId).not.toBe(TRACE_ID) + expect(span.parentSpanId).toBeUndefined() + }) + + it('starts a fresh root when the parent is not a span, as a duplicated header is', async () => { + const traces = createTraces() + traces.startSpan('handler', { parent: [`00-${TRACE_ID}-${REMOTE_SPAN_ID}-01`] as unknown as string }).end() + await traces.flush() + + const [span] = sentSpans() + expect(span.traceId).not.toBe(TRACE_ID) + expect(span.parentSpanId).toBeUndefined() + }) + }) + + describe('withSpan', () => { + it('ends the span and returns the callback result', async () => { + const traces = createTraces() + const result = traces.withSpan('job', () => 'value') + await traces.flush() + + expect(result).toBe('value') + expect(sentSpans()).toHaveLength(1) + expect(sentSpans()[0].status).toBeUndefined() + }) + + it('accepts options before the callback', async () => { + const traces = createTraces() + traces.withSpan('job', { kind: 'server', attributes: { plan: 'pro' } }, () => undefined) + await traces.flush() + + const [span] = sentSpans() + expect(span.kind).toBe(2) + expect(span.attributes).toContainEqual({ key: 'plan', value: { stringValue: 'pro' } }) + }) + + it('makes the span active for the callback', () => { + const traces = createTraces() + traces.withSpan('outer', (span) => { + expect(traces.getActiveSpan()).toBe(span) + }) + expect(traces.getActiveSpan()).toBeNull() + }) + + it('nests spans started inside the callback', async () => { + const traces = createTraces() + traces.withSpan('outer', () => { + traces.withSpan('inner', () => undefined) + }) + await traces.flush() + + const inner = sentSpans().find((s) => s.name === 'inner')! + const outer = sentSpans().find((s) => s.name === 'outer')! + expect(inner.traceId).toBe(outer.traceId) + expect(inner.parentSpanId).toBe(outer.spanId) + }) + + it('lets an explicit parent override the active span', async () => { + const traces = createTraces() + const detached = traces.startSpan('detached') + traces.withSpan('outer', () => { + traces.withSpan('inner', { parent: detached }, () => undefined) + }) + detached.end() + await traces.flush() + + const inner = sentSpans().find((s) => s.name === 'inner')! + const detachedSpan = sentSpans().find((s) => s.name === 'detached')! + expect(inner.parentSpanId).toBe(detachedSpan.spanId) + }) + + it('records a thrown error and rethrows it unmodified', async () => { + const traces = createTraces() + const thrown = new TypeError('boom') + + expect(() => + traces.withSpan('job', () => { + throw thrown + }) + ).toThrow(thrown) + + await traces.flush() + const [span] = sentSpans() + expect(span.status).toEqual({ code: 2, message: 'boom' }) + expect(span.events?.[0]).toMatchObject({ + name: 'exception', + attributes: [ + { key: 'exception.type', value: { stringValue: 'TypeError' } }, + { key: 'exception.message', value: { stringValue: 'boom' } }, + ], + }) + }) + + it('ends an async callback at settle, not when it returns its promise', async () => { + const traces = createTraces({ maxExportBatchSize: 1 }) + let finishWork!: () => void + const work = new Promise((resolve) => { + finishWork = resolve + }) + + const pending = traces.withSpan('job', () => work) + + await Promise.resolve() + expect(mockInstance._sendTracesBatch).not.toHaveBeenCalled() + + finishWork() + await pending + await traces.flush() + + expect(sentSpans()).toHaveLength(1) + }) + + it('covers the awaited duration', async () => { + const traces = createTraces() + const pending = traces.withSpan('job', async () => { + await new Promise((resolve) => setTimeout(resolve, 80)) + }) + await jest.advanceTimersByTimeAsync(80) + await pending + await traces.flush() + + const [span] = sentSpans() + expect(Number(span.endTimeUnixNano)).toBeGreaterThan(Number(span.startTimeUnixNano)) + }) + + it('records a rejection and rethrows it unmodified', async () => { + const traces = createTraces() + const thrown = new Error('async boom') + + await expect(traces.withSpan('job', async () => Promise.reject(thrown))).rejects.toBe(thrown) + + await traces.flush() + expect(sentSpans()[0].status).toEqual({ code: 2, message: 'async boom' }) + }) + + it('treats an explicit ok status as final when the callback throws', async () => { + const traces = createTraces() + expect(() => + traces.withSpan('job', (span) => { + span.setStatus('ok') + throw new Error('boom') + }) + ).toThrow('boom') + + await traces.flush() + const [span] = sentSpans() + expect(span.status).toEqual({ code: 1 }) + // The exception event is still attached — only the status is protected. + expect(span.events?.[0].name).toBe('exception') + }) + + it('runs the callback once with an inert handle when tracing cannot run', async () => { + const traces = createTraces({}, createMockInstance({ optedOut: true })) + const fn = jest.fn(() => 'value') + + expect(traces.withSpan('job', fn)).toBe('value') + expect(fn).toHaveBeenCalledTimes(1) + expect(fn).toHaveBeenCalledWith(NOOP_SPAN) + expect(traces.getActiveSpan()).toBeNull() + await traces.flush() + expect(sentSpans()).toHaveLength(0) + }) + }) + + describe('auto-context', () => { + it('attaches the distinct id and session id as the product join keys', async () => { + context = { distinctId: 'user-123', sessionId: 'session-123' } + const traces = createTraces() + traces.startSpan('checkout').end() + await traces.flush() + + expect(sentSpans()[0].attributes).toEqual( + expect.arrayContaining([ + { key: 'posthogDistinctId', value: { stringValue: 'user-123' } }, + { key: 'sessionId', value: { stringValue: 'session-123' } }, + ]) + ) + }) + + it('omits keys with no value', async () => { + context = { distinctId: 'user-123' } + const traces = createTraces() + traces.startSpan('checkout').end() + await traces.flush() + + expect(sentSpans()[0].attributes?.map((a) => a.key)).toEqual(['posthogDistinctId']) + }) + + it('freezes the snapshot at span start', async () => { + context = { distinctId: 'a' } + const traces = createTraces() + const span = traces.startSpan('checkout') + context = { distinctId: 'b' } + span.end() + await traces.flush() + + expect(sentSpans()[0].attributes).toContainEqual({ + key: 'posthogDistinctId', + value: { stringValue: 'a' }, + }) + }) + + it('lets user attributes win on collision', async () => { + context = { distinctId: 'a' } + const traces = createTraces() + traces.startSpan('checkout', { attributes: { posthogDistinctId: 'override' } }).end() + await traces.flush() + + expect(sentSpans()[0].attributes).toContainEqual({ + key: 'posthogDistinctId', + value: { stringValue: 'override' }, + }) + }) + + it('maps the client-platform navigation keys', async () => { + // These attribute names are a wire contract the browser and mobile hosts + // will encode against; renaming one silently breaks the join. + context = { currentUrl: 'https://example.com/cart', screenName: 'Cart', appState: 'foreground' } + const traces = createTraces() + traces.startSpan('checkout').end() + await traces.flush() + + const attributes = sentSpans()[0].attributes ?? [] + expect(attributes).toEqual( + expect.arrayContaining([ + { key: 'url.full', value: { stringValue: 'https://example.com/cart' } }, + { key: 'screen.name', value: { stringValue: 'Cart' } }, + { key: 'app.state', value: { stringValue: 'foreground' } }, + ]) + ) + }) + + it('still records the span when reading context throws', async () => { + const traces = new PostHogTraces( + mockInstance, + resolveForTest(), + logger, + () => { + throw new Error('no context') + }, + new SyncSpanContextManager() + ) + traces.startSpan('checkout').end() + await traces.flush() + + expect(sentSpans()).toHaveLength(1) + }) + }) + + describe('gating', () => { + it('drops a span whose user opted out mid-trace, without throwing', async () => { + const instance = createMockInstance() + const traces = createTraces({}, instance) + const span = traces.startSpan('checkout') + + instance.optedOut = true + expect(() => span.end()).not.toThrow() + + await traces.flush() + expect(instance._sendTracesBatch).not.toHaveBeenCalled() + }) + }) + + describe('export', () => { + it('flushes when the queue reaches the batch size', async () => { + const traces = createTraces({ maxExportBatchSize: 2 }) + traces.startSpan('a').end() + expect(mockInstance._sendTracesBatch).not.toHaveBeenCalled() + + traces.startSpan('b').end() + await traces.flush() + expect(sentSpans()).toHaveLength(2) + }) + + it('flushes on the interval timer', async () => { + const traces = createTraces({ flushIntervalMs: 1000 }) + traces.startSpan('a').end() + expect(mockInstance._sendTracesBatch).not.toHaveBeenCalled() + + await jest.advanceTimersByTimeAsync(1000) + expect(sentSpans()).toHaveLength(1) + }) + + it('sends one resource and one scope per batch', async () => { + const traces = createTraces({ serviceName: 'checkout-api' }) + traces.startSpan('a').end() + traces.startSpan('b').end() + await traces.flush() + + const [payload] = sentPayloads() + expect(payload.resourceSpans).toHaveLength(1) + expect(payload.resourceSpans[0].scopeSpans).toHaveLength(1) + expect(payload.resourceSpans[0].scopeSpans[0].spans).toHaveLength(2) + expect(payload.resourceSpans[0].resource.attributes).toContainEqual({ + key: 'service.name', + value: { stringValue: 'checkout-api' }, + }) + }) + + it('splits a backlog across batches', async () => { + const traces = createTraces({ maxExportBatchSize: 2 }) + for (let i = 0; i < 5; i++) { + traces.startSpan(`span-${i}`).end() + } + await traces.flush() + + expect(sentPayloads().length).toBeGreaterThanOrEqual(3) + expect(sentSpans()).toHaveLength(5) + }) + + it('joins an in-flight flush rather than double-sending', async () => { + const traces = createTraces() + traces.startSpan('a').end() + + const [first, second] = [traces.flush(), traces.flush()] + await Promise.all([first, second]) + + expect(mockInstance._sendTracesBatch).toHaveBeenCalledTimes(1) + expect(sentSpans()).toHaveLength(1) + }) + + it('drops the incoming span when the queue is full, keeping queued parents', async () => { + // Queued spans are completed parents whose children may already have been + // exported; evicting them would break assembled traces retroactively. + const traces = createTraces({ maxQueueSize: 2, maxExportBatchSize: 100 }) + traces.startSpan('first').end() + traces.startSpan('second').end() + traces.startSpan('third').end() + await traces.flush() + + expect(sentSpans().map((s) => s.name)).toEqual(['first', 'second']) + expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('the queue is full')) + }) + }) + + describe('export failures', () => { + it('halves the batch and resends the same spans on 413', async () => { + const outcomes: SendTracesBatchOutcome[] = [{ kind: 'too-large' }, { kind: 'ok' }, { kind: 'ok' }] + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.resolve(outcomes.shift() ?? { kind: 'ok' })), + }) + const traces = createTraces({ maxExportBatchSize: 4 }, instance) + for (let i = 0; i < 4; i++) { + traces.startSpan(`span-${i}`).end() + } + await traces.flush() + + const batchSizes = sentPayloads(instance).map((p) => p.resourceSpans[0].scopeSpans[0].spans.length) + expect(batchSizes).toEqual([4, 2, 2]) + expect(sentSpans(instance)).toHaveLength(8) + }) + + it('shrinks below the queue depth on 413 rather than resending the same body', async () => { + // The batch the server rejected is what has to get smaller. Halving the + // configured maximum leaves `size` unchanged whenever the queue is + // shallower than it — the ordinary timer-flush case. + const instance = createMockInstance({ + _sendTracesBatch: jest.fn().mockResolvedValueOnce({ kind: 'too-large' }).mockResolvedValue({ kind: 'ok' }), + }) + const traces = createTraces({ maxExportBatchSize: 512 }, instance) + for (let i = 0; i < 3; i++) { + traces.startSpan(`span-${i}`).end() + } + await traces.flush() + + const batchSizes = sentPayloads(instance).map((p) => p.resourceSpans[0].scopeSpans[0].spans.length) + expect(batchSizes).toEqual([3, 1, 2]) + }) + + it('ramps the batch size back up after a 413 shrink', async () => { + // A one-off oversized payload shouldn't permanently halve throughput. + const instance = createMockInstance({ + _sendTracesBatch: jest.fn().mockResolvedValueOnce({ kind: 'too-large' }).mockResolvedValue({ kind: 'ok' }), + }) + const traces = createTraces({ maxExportBatchSize: 4 }, instance) + for (let i = 0; i < 4; i++) { + traces.startSpan(`span-${i}`).end() + } + await traces.flush() + + // Shrunk to 2, then +1 per healthy send across the two batches that drained it. + instance._sendTracesBatch.mockClear() + for (let i = 0; i < 4; i++) { + traces.startSpan(`later-${i}`).end() + } + await traces.flush() + + expect(sentPayloads(instance)[0].resourceSpans[0].scopeSpans[0].spans.length).toBeGreaterThan(2) + }) + + it('drops a single span the server rejects as too large', async () => { + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.resolve({ kind: 'too-large' as const })), + }) + const traces = createTraces({ maxExportBatchSize: 1 }, instance) + traces.startSpan('huge').end() + await traces.flush() + + expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('too large')) + + // The span must actually leave the queue, or it is re-POSTed on every + // flush for the life of the process. + instance._sendTracesBatch.mockResolvedValue({ kind: 'ok' }) + traces.startSpan('later').end() + await traces.flush() + expect(sentSpans(instance).map((s) => s.name)).toEqual(['huge', 'later']) + }) + + it('names the reason for each kind of drop', async () => { + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.resolve({ kind: 'fatal' as const, error: new Error('400') })), + }) + const traces = createTraces({ maxExportBatchSize: 1 }, instance) + traces.startSpan('poison').end() + await traces.flush() + + // A poison batch is not a full queue; telling an operator to reduce span + // volume would send them after the wrong problem. + expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('rejected the batch')) + expect(logger.warn).not.toHaveBeenCalledWith(expect.stringContaining('queue is full')) + }) + + it('warns again about drops on a later flush', async () => { + // Warning once per process would leave the SDK silent about every + // subsequent drop for the life of the app. + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.resolve({ kind: 'fatal' as const, error: new Error('400') })), + }) + const traces = createTraces({ maxExportBatchSize: 1 }, instance) + + traces.startSpan('a').end() + await traces.flush() + traces.startSpan('b').end() + await traces.flush() + + expect((logger.warn as jest.Mock).mock.calls.length).toBeGreaterThan(1) + }) + + it('keeps spans queued on a retriable failure', async () => { + const instance = createMockInstance({ + _sendTracesBatch: jest + .fn() + .mockResolvedValueOnce({ kind: 'retry-later', error: new Error('network') }) + .mockResolvedValue({ kind: 'ok' }), + }) + const traces = createTraces({}, instance) + traces.startSpan('a').end() + + await traces.flush() + expect(sentSpans(instance)).toHaveLength(1) + + await traces.flush() + expect(sentSpans(instance)).toHaveLength(2) + expect(sentSpans(instance)[1].name).toBe('a') + }) + + it('drops a poison batch rather than wedging the queue', async () => { + const instance = createMockInstance({ + _sendTracesBatch: jest + .fn() + .mockResolvedValueOnce({ kind: 'fatal', error: new Error('400') }) + .mockResolvedValue({ kind: 'ok' }), + }) + const traces = createTraces({ maxExportBatchSize: 1 }, instance) + traces.startSpan('poison').end() + traces.startSpan('good').end() + await traces.flush() + + expect(sentSpans(instance).map((s) => s.name)).toEqual(['poison', 'good']) + + instance._sendTracesBatch.mockClear() + await traces.flush() + expect(instance._sendTracesBatch).not.toHaveBeenCalled() + }) + + it('does not surface a transport failure through span.end()', async () => { + // Ending a span is application control flow — it must never throw because + // the exporter is broken. + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.reject(new Error('transport exploded'))), + }) + const traces = createTraces({ maxExportBatchSize: 1 }, instance) + + expect(() => traces.startSpan('a').end()).not.toThrow() + // Let the background flush settle; the rejection is swallowed there. + await jest.advanceTimersByTimeAsync(0) + }) + + it('surfaces a transport failure through an explicit flush()', async () => { + // flush() is the caller asking to be told, so it propagates — matching + // how the logs and metrics pipelines behave. + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => Promise.reject(new Error('transport exploded'))), + }) + const traces = createTraces({ maxExportBatchSize: 100 }, instance) + traces.startSpan('a').end() + + await expect(traces.flush()).rejects.toThrow('transport exploded') + }) + }) + + describe('poison attributes', () => { + it('encodes a circular attribute instead of blowing the stack', async () => { + const traces = createTraces() + const cyclic: any = { name: 'order' } + cyclic.self = cyclic + + traces.startSpan('checkout', { attributes: { payload: cyclic } }).end() + await traces.flush() + + expect(sentSpans()).toHaveLength(1) + expect(JSON.stringify(sentPayloads()[0])).toContain('[Circular]') + }) + + it('treats a repeated sibling reference as duplication, not a cycle', async () => { + const traces = createTraces() + const shared = { id: 1 } + + traces.startSpan('checkout', { attributes: { a: shared, b: shared } as any }).end() + await traces.flush() + + expect(JSON.stringify(sentPayloads()[0])).not.toContain('[Circular]') + }) + + it('keeps a span whose attribute getter throws, marking only that key', async () => { + // The shared encoder contains a throwing getter at the key it belongs to, + // so the span keeps its name, timing and every other attribute instead of + // being dropped whole. + const traces = createTraces({ maxExportBatchSize: 1 }) + const exploding = { + ok: 1, + get boom() { + throw new Error('getter exploded') + }, + } + + traces.startSpan('poison', { attributes: { payload: exploding as any } }).end() + traces.startSpan('healthy').end() + await traces.flush() + + expect(sentSpans().map((s) => s.name)).toEqual(['poison', 'healthy']) + expect(JSON.stringify(sentPayloads()[0])).toContain('[Unserializable]') + expect(JSON.stringify(sentPayloads()[0])).toContain('"intValue":"1"') + }) + }) + + describe('drain progress', () => { + it('drains a span that arrives while a send is in flight', async () => { + // Queue length can't measure progress: one span out and one in leaves it + // unchanged, which would read as "no progress" and strand the new span — + // and shutdown() then discards it. + let onSend = (): void => {} + const instance = createMockInstance({ + _sendTracesBatch: jest.fn(() => { + onSend() + onSend = (): void => {} + return Promise.resolve({ kind: 'ok' as const }) + }), + }) + const traces = createTraces({ maxExportBatchSize: 10 }, instance) + onSend = (): void => traces.startSpan('arrived-mid-flight').end() + + traces.startSpan('first').end() + await traces.flush() + + expect(sentSpans(instance).map((s) => s.name)).toEqual(['first', 'arrived-mid-flight']) + }) + + it('terminates rather than spinning when a batch size of zero slips through', async () => { + // Core must not depend on every host clamping its config. + const traces = createTraces({ maxExportBatchSize: 0 }) + traces.startSpan('a').end() + + await traces.flush() + + expect(sentSpans()).toHaveLength(1) + }) + }) + + describe('reset', () => { + it('abandons an in-flight pass instead of splicing spans it never sent', async () => { + let release!: (outcome: SendTracesBatchOutcome) => void + const instance = createMockInstance({ + _sendTracesBatch: jest.fn( + () => + new Promise((resolve) => { + release = resolve + }) + ), + }) + const traces = createTraces({ maxExportBatchSize: 10 }, instance) + + traces.startSpan('sent-a').end() + traces.startSpan('sent-b').end() + const inFlight = traces.flush() + await Promise.resolve() + + // shutdown() lost the race and tore the pipeline down. + traces.reset() + traces.startSpan('after-reset').end() + + release({ kind: 'ok' }) + await inFlight + + expect((traces as any)._queue.map((r: any) => r.name)).toEqual(['after-reset']) + }) + + it('clears the queue', async () => { + const traces = createTraces() + traces.startSpan('a').end() + traces.reset() + await traces.flush() + + expect(mockInstance._sendTracesBatch).not.toHaveBeenCalled() + }) + }) +}) diff --git a/packages/core/src/traces/index.ts b/packages/core/src/traces/index.ts new file mode 100644 index 0000000000..863a214468 --- /dev/null +++ b/packages/core/src/traces/index.ts @@ -0,0 +1,475 @@ +import type { Span, SpanAttributes, StartSpanOptions } from '@posthog/types' +import type { Logger } from '../types' +import type { + OtlpSpan, + ResolvedTracesConfig, + SpanContextManager, + SpanRecord, + TraceSdkContext, + TracesHost, +} from './types' +import { NOOP_SPAN, PostHogSpan, describeError } from './span' +import { newSpanId, newTraceId } from './ids' +import { parseTraceparent, sanitizeTracestate } from './traceparent' +import { resolveStartTime, sanitizeName } from './sanitize' +import { buildOtlpSpan, buildOtlpTracesPayload, buildTracesResourceAttributes } from './otlp' +import { isPromise, safeSetTimeout } from '../utils' + +type SpanCallback = (span: Span) => T + +interface ParentContext { + traceId: string + parentSpanId?: string + traceState?: string +} + +/** + * The traces pipeline: span creation, active-span parenting, and OTLP export. + * + * Deliberately separate from the analytics-events pipeline — its own queue, its + * own endpoint, its own flush cycle — mirroring how logs and metrics are modeled. + */ +export class PostHogTraces { + private _queue: SpanRecord[] = [] + private _flushTimer?: ReturnType + // Serializes flushes: a second caller joins the first rather than racing it + // and double-sending the head of the queue. + private _flushPromise: Promise | null = null + // Mutable: halved on 413 to shrink the next POST, then ramped back up by one + // span per healthy send so a single oversized batch doesn't permanently + // degrade throughput. + private _maxExportBatchSize: number + private _droppedWarned = false + // Bumped by reset(); a pass whose generation is stale abandons the queue. + private _generation = 0 + + constructor( + private readonly _instance: TracesHost, + private readonly _config: ResolvedTracesConfig, + private readonly _logger: Logger, + private readonly _getContext: () => TraceSdkContext, + private readonly _contextManager: SpanContextManager + ) { + this._maxExportBatchSize = _config.maxExportBatchSize + } + + // ========================================================================== + // Public API + // ========================================================================== + + /** + * Starts a span without making it active. Always returns a handle — an inert + * one when tracing cannot run — so calling code never branches. + */ + startSpan(name: string, options?: StartSpanOptions): Span { + if (this._instance.isDisabled || this._instance.optedOut) { + return NOOP_SPAN + } + + const explicitParent = options?.parent + if (explicitParent && typeof explicitParent !== 'string' && !(explicitParent instanceof PostHogSpan)) { + if (typeof (explicitParent as Span).traceparent === 'function') { + // A child of a no-op is itself a no-op, never an orphan with invented ids. + // A foreign Span implementation lands here too, which is why it is logged. + this._logger.debug('Span parent is not a span from this SDK; returning an inert span') + return NOOP_SPAN + } + // Not a span at all — `req.headers.traceparent` is `string[]` when the + // header arrives twice, and W3C treats that as no inbound context. Ignored + // like a malformed traceparent string rather than costing the span. + this._logger.debug('Ignoring an unusable span parent') + } + + const parent = this._resolveParent(options) + + const now = Date.now() + const startTime = resolveStartTime(options?.startTime, now, this._logger) + + return new PostHogSpan( + { + traceId: parent?.traceId ?? newTraceId(), + spanId: newSpanId(), + parentSpanId: parent?.parentSpanId, + traceState: parent?.traceState, + name: sanitizeName(name, 'Span name', this._logger), + kind: options?.kind ?? 'internal', + // Auto-context first so user-supplied attributes win on collision. + attributes: { ...this._autoContextAttributes(), ...(options?.attributes ?? {}) }, + startTime, + backdated: startTime !== now, + }, + (record) => this._onSpanEnd(record), + this._logger + ) + } + + /** + * Runs a callback with a span active for its duration and guarantees the span + * ends — at return for a sync callback, at settle for an async one. + * + * A throw or rejection is recorded on the span and rethrown unmodified: the + * SDK never swallows application control flow. + */ + withSpan(name: string, fn: SpanCallback): T + withSpan(name: string, options: StartSpanOptions, fn: SpanCallback): T + withSpan(name: string, optionsOrFn: StartSpanOptions | SpanCallback, maybeFn?: SpanCallback): T { + const options = typeof optionsOrFn === 'function' ? undefined : optionsOrFn + const fn = (typeof optionsOrFn === 'function' ? optionsOrFn : maybeFn) as SpanCallback + + const span = this.startSpan(name, options) + + try { + // A no-op span is never activated, so `getActiveSpan()` inside the + // callback reads null — callbacks should use the handle they're given. + const result = span === NOOP_SPAN ? fn(span) : this._contextManager.with(span, () => fn(span)) + + if (isPromise(result)) { + return result.then( + (value: unknown) => { + span.end() + return value + }, + (error: unknown) => { + this._recordCallbackError(span, error) + span.end() + throw error + } + ) as T + } + + span.end() + return result + } catch (error) { + this._recordCallbackError(span, error) + span.end() + throw error + } + } + + /** The active span, or `null` outside any `withSpan` callback. */ + getActiveSpan(): Span | null { + return this._contextManager.active() ?? null + } + + /** + * Drains the span queue. + * + * Runs repeated passes rather than joining a single in-flight one: a flush + * arriving mid-flight would otherwise return once the active pass finished + * with its own watermark, leaving spans enqueued after that watermark behind — + * which would make `shutdown()` silently drop them. + * + * A pass reports how many spans it removed, and the drain stops as soon as one + * removes none. Queue length can't stand in for that: a pass that sends one + * span while another arrives mid-send leaves the length unchanged, which reads + * as "no progress" and abandons the new span. + */ + async flush(): Promise { + for (;;) { + if (!this._queue.length) { + return + } + + const inFlight = this._flushPromise + const removed = await (inFlight ?? this._startFlush()) + + // No progress means a retriable failure, an abandoned pass, or spans + // arriving as fast as we send them. Either way, stop rather than spin. + if (!removed) { + return + } + } + } + + private _startFlush(): Promise { + this._clearFlushTimer() + const promise = this._flushInner().finally(() => { + // Only clear the slot this call installed: a `reset()` mid-flight may + // already have installed a newer one. + if (this._flushPromise === promise) { + this._flushPromise = null + } + this._armFlushTimerIfQueued() + }) + this._flushPromise = promise + return promise + } + + /** Clears the queue and timer. Used on shutdown and between tests. */ + reset(): void { + this._clearFlushTimer() + this._queue = [] + this._flushPromise = null + // Abandons any in-flight pass: it resumes against a queue it no longer + // owns, so without this it would splice out spans it never sent. + this._generation++ + this._maxExportBatchSize = this._config.maxExportBatchSize + this._droppedWarned = false + } + + // ========================================================================== + // Span creation internals + // ========================================================================== + + /** + * Resolves a span's parent, in precedence order: an explicit `parent`, then + * the active span, then none (a fresh root). + * + * A no-op explicit parent is rejected before this runs, in `startSpan`. + */ + private _resolveParent(options?: StartSpanOptions): ParentContext | undefined { + const explicit = options?.parent + + if (typeof explicit === 'string') { + const remote = parseTraceparent(explicit) + if (!remote) { + // A malformed traceparent starts a fresh root rather than throwing — + // an inbound header is caller-controlled and often absent. + this._logger.debug('Ignoring malformed traceparent; starting a new trace') + return undefined + } + return { + traceId: remote.traceId, + parentSpanId: remote.spanId, + traceState: sanitizeTracestate(options?.tracestate), + } + } + + if (explicit instanceof PostHogSpan) { + // `tracestate` is ignored for handle parents — the child inherits the + // parent span's tracestate instead. + return explicit.childContext() + } + + const active = this._contextManager.active() + return active instanceof PostHogSpan ? active.childContext() : undefined + } + + /** + * PostHog context snapshotted at span start. These are the product's join + * keys — they're what makes a span reachable from a person or a session. + */ + private _autoContextAttributes(): SpanAttributes { + let context: TraceSdkContext + try { + context = this._getContext() + } catch (error) { + this._logger.debug('Failed to read tracing context; span will carry no PostHog attributes', error) + return {} + } + + const attributes: SpanAttributes = {} + if (context.distinctId) { + attributes.posthogDistinctId = context.distinctId + } + if (context.sessionId) { + attributes.sessionId = context.sessionId + } + if (context.currentUrl) { + attributes['url.full'] = context.currentUrl + } + if (context.screenName) { + attributes['screen.name'] = context.screenName + } + if (context.appState) { + attributes['app.state'] = context.appState + } + return attributes + } + + /** + * Records a callback failure on the span: an `exception` event always, plus + * status `error` unless the callback explicitly marked the span `ok`. + */ + private _recordCallbackError(span: Span, error: unknown): void { + if (!(span instanceof PostHogSpan)) { + return + } + const { type, message } = describeError(error) + span.addEvent('exception', { 'exception.type': type, 'exception.message': message }) + if (!span.statusIsExplicitlyOk) { + span.setStatus('error', message) + } + } + + // ========================================================================== + // Queue and export + // ========================================================================== + + private _onSpanEnd(record: SpanRecord): void { + // Re-checked at end, not just at start: opting out mid-trace must stop the + // span exporting, without throwing into code holding a live handle. + if (this._instance.isDisabled || this._instance.optedOut) { + return + } + + if (this._queue.length >= this._config.maxQueueSize) { + // Drop the incoming span rather than evicting queued ones: the oldest + // queued spans are completed parents whose children may already have been + // exported, and dropping them breaks assembled traces retroactively. + this._recordDrop( + 1, + `the queue is full (${this._config.maxQueueSize}) — raise the flush frequency or reduce span volume` + ) + return + } + + this._queue.push(record) + + if (this._queue.length >= this._maxExportBatchSize) { + this._flushInBackground() + } else { + this._armFlushTimerIfQueued() + } + } + + private _recordDrop(count: number, reason: string): void { + if (!this._droppedWarned) { + this._droppedWarned = true + this._logger.warn(`Dropping ${count} span(s): ${reason}`) + } + } + + /** + * Encodes a batch, dropping any single span whose attributes cannot be + * encoded — a throwing getter, most likely, since cycles degrade to a marker. + * + * Encoding runs before the send and outside the outcome handling, so an + * unguarded throw here would leave the queue unspliced and every later flush + * would die on the same span, taking the whole pipeline down silently. Both + * sibling pipelines guard their serialization the same way. + */ + private _encodeBatch(batch: SpanRecord[]): OtlpSpan[] { + const encoded: OtlpSpan[] = [] + for (const record of batch) { + try { + encoded.push(buildOtlpSpan(record, this._logger)) + } catch (error) { + this._logger.debug('Failed to encode a span; dropping it', error) + this._recordDrop(1, 'its attributes could not be encoded') + } + } + return encoded + } + + /** Returns how many spans it removed from the queue, sent or dropped. */ + private async _flushInner(): Promise { + if (!this._queue.length) { + return 0 + } + + const resourceAttributes = buildTracesResourceAttributes( + this._config, + this._instance.getLibraryId(), + this._instance.getLibraryVersion() + ) + const scopeName = this._instance.getLibraryId() + const scopeVersion = this._instance.getLibraryVersion() + + // Warn again about drops in this pass even if an earlier one already did. + this._droppedWarned = false + + // Bounded by the queue depth at flush start, so spans enqueued mid-drain + // ride the next flush instead of extending this one indefinitely. + let remaining = this._queue.length + let removed = 0 + const generation = this._generation + + while (remaining > 0 && this._queue.length > 0) { + // Floor at one: a host that resolved a non-positive batch size would + // otherwise make no progress and loop forever on an empty batch. + const size = Math.max(1, Math.min(this._maxExportBatchSize, remaining, this._queue.length)) + const batch = this._queue.slice(0, size) + const spans = this._encodeBatch(batch) + + if (!spans.length) { + // Nothing survived encoding; drop the batch rather than re-encoding it + // on every future flush. + this._queue.splice(0, size) + remaining -= size + removed += size + continue + } + + const outcome = await this._instance._sendTracesBatch( + buildOtlpTracesPayload(spans, resourceAttributes, scopeName, scopeVersion, this._logger) + ) + + if (generation !== this._generation) { + // reset() ran while the send was in flight — the client was torn down, + // so this pass no longer owns the queue and must not touch it. + return removed + } + + if (outcome.kind === 'ok') { + this._queue.splice(0, size) + remaining -= size + removed += size + // Ramp back toward the configured max after a 413 shrink. + if (this._maxExportBatchSize < this._config.maxExportBatchSize) { + this._maxExportBatchSize++ + } + continue + } + + if (outcome.kind === 'too-large') { + if (size === 1) { + // A single span the server won't accept at any batch size. Dropping + // it is the only way to stop it wedging the queue behind it. + this._queue.splice(0, 1) + remaining -= 1 + removed += 1 + this._recordDrop(1, 'the ingestion endpoint rejected it as too large') + continue + } + // Halve the batch the server rejected, not the configured maximum: when the + // queue is shallower than the maximum, shrinking the maximum leaves the batch + // the same size and resends the identical body. + this._maxExportBatchSize = Math.max(1, Math.floor(size / 2)) + this._logger.debug(`Batch too large; retrying the same spans in batches of ${this._maxExportBatchSize}`) + continue + } + + if (outcome.kind === 'retry-later') { + // Keep the spans queued; the flush timer picks them up again. + this._logger.debug('Span export failed; retrying on the next flush', outcome.error) + return removed + } + + // Non-retriable: a poison batch or a bad key. Drop it so it can't wedge + // the queue behind it. + this._logger.debug('Dropping a span batch the ingestion endpoint rejected', outcome.error) + this._queue.splice(0, size) + remaining -= size + removed += size + this._recordDrop(size, 'the ingestion endpoint rejected the batch') + } + + return removed + } + + private _flushInBackground(): void { + void this.flush().catch((error) => { + // Background flushes have no caller to surface to; an explicit flush() + // still rejects. + this._logger.debug('Background span flush failed', error) + }) + } + + private _armFlushTimerIfQueued(): void { + if (this._flushTimer || !this._queue.length) { + return + } + this._flushTimer = safeSetTimeout(() => { + this._flushTimer = undefined + this._flushInBackground() + }, this._config.flushIntervalMs) + } + + private _clearFlushTimer(): void { + if (this._flushTimer) { + clearTimeout(this._flushTimer) + this._flushTimer = undefined + } + } +} diff --git a/packages/core/src/traces/otlp.spec.ts b/packages/core/src/traces/otlp.spec.ts new file mode 100644 index 0000000000..5e4703cb31 --- /dev/null +++ b/packages/core/src/traces/otlp.spec.ts @@ -0,0 +1,261 @@ +import { + buildOtlpSpan, + buildOtlpTracesPayload, + buildTracesResourceAttributes, + msToUnixNanoString, + spanKindToOtlp, +} from './otlp' +import type { ResolvedTracesConfig, SpanRecord } from './types' + +const record = (overrides: Partial = {}): SpanRecord => ({ + traceId: '4bf92f3577b34da6a3ce929d0e0e4736', + spanId: '00f067aa0ba902b7', + name: 'checkout', + kind: 'internal', + attributes: {}, + events: [], + startTime: 1_700_000_000_000, + endTime: 1_700_000_000_080, + ...overrides, +}) + +describe('OTLP span encoding', () => { + describe('msToUnixNanoString', () => { + it('encodes milliseconds as a nanosecond string', () => { + expect(msToUnixNanoString(1_700_000_000_000)).toBe('1700000000000000000') + }) + + it('keeps sub-millisecond precision', () => { + expect(msToUnixNanoString(1_700_000_000_000.5)).toBe('1700000000000500000') + }) + + it('stays exact beyond Number.MAX_SAFE_INTEGER', () => { + // The whole point of string concatenation over `ms * 1e6`, which would + // silently lose precision at this magnitude. + const encoded = msToUnixNanoString(1_700_000_000_123) + expect(encoded).toBe('1700000000123000000') + expect(Number(encoded)).toBeGreaterThan(Number.MAX_SAFE_INTEGER) + }) + + it.each([0.9999999, 1.9999999, 999.9999999])( + 'carries a rounded-up fraction into the next millisecond for %p', + (ms) => { + // Without the carry the padded fraction gains a seventh digit, producing + // a malformed timestamp that 400s the whole request. Unreachable from a + // real clock — float64 quantization at epoch-ms magnitude keeps the + // fraction well below the carry — but reachable via a caller-supplied + // `startTime`, which the validity check accepts anywhere in [0, MAX]. + const encoded = msToUnixNanoString(ms) + expect(encoded).toHaveLength(String(Math.round(ms)).length + 6) + expect(encoded).toMatch(/^\d+$/) + } + ) + }) + + describe('spanKindToOtlp', () => { + it.each([ + ['internal', 1], + ['server', 2], + ['client', 3], + ['producer', 4], + ['consumer', 5], + ] as const)('maps %s to %i', (kind, expected) => { + expect(spanKindToOtlp(kind)).toBe(expected) + }) + + it('defaults to internal', () => { + expect(spanKindToOtlp(undefined)).toBe(1) + }) + }) + + describe('buildOtlpSpan', () => { + it('builds the minimal shape', () => { + expect(buildOtlpSpan(record())).toEqual({ + traceId: '4bf92f3577b34da6a3ce929d0e0e4736', + spanId: '00f067aa0ba902b7', + name: 'checkout', + kind: 1, + startTimeUnixNano: '1700000000000000000', + endTimeUnixNano: '1700000000080000000', + flags: 1, + }) + }) + + it('omits status when it was never set', () => { + expect(buildOtlpSpan(record())).not.toHaveProperty('status') + }) + + it('encodes ok and error status codes', () => { + expect(buildOtlpSpan(record({ status: { code: 'ok' } })).status).toEqual({ code: 1 }) + expect(buildOtlpSpan(record({ status: { code: 'error', message: 'boom' } })).status).toEqual({ + code: 2, + message: 'boom', + }) + }) + + it('includes parent, tracestate, attributes and events when present', () => { + const span = buildOtlpSpan( + record({ + parentSpanId: 'b7ad6b7169203331', + traceState: 'vendor=abc', + attributes: { plan: 'pro' }, + events: [{ name: 'cache miss', timestamp: 1_700_000_000_040 }], + }) + ) + expect(span.parentSpanId).toBe('b7ad6b7169203331') + expect(span.traceState).toBe('vendor=abc') + expect(span.attributes).toEqual([{ key: 'plan', value: { stringValue: 'pro' } }]) + expect(span.events).toEqual([{ name: 'cache miss', timeUnixNano: '1700000000040000000' }]) + }) + + it('always sets the sampled trace flag', () => { + expect(buildOtlpSpan(record()).flags).toBe(1) + }) + }) + + describe('buildTracesResourceAttributes', () => { + const config = (partial: Partial = {}): ResolvedTracesConfig => ({ + flushIntervalMs: 5000, + maxExportBatchSize: 512, + maxQueueSize: 2048, + ...partial, + }) + + it('always emits service.name', () => { + // The server reads service_name only from this attribute and stores an + // empty string when it's missing, leaving spans unattributable. + expect(buildTracesResourceAttributes(config(), 'posthog-node', '1.0.0')['service.name']).toBe('unknown_service') + }) + + it('uses the configured service name', () => { + expect(buildTracesResourceAttributes(config({ serviceName: 'checkout' }), 'posthog-node', '1.0.0')).toMatchObject( + { + 'service.name': 'checkout', + } + ) + }) + + it('includes environment and version only when set', () => { + const attributes = buildTracesResourceAttributes( + config({ environment: 'production', serviceVersion: '2.1.0' }), + 'posthog-node', + '1.0.0' + ) + expect(attributes['deployment.environment']).toBe('production') + expect(attributes['service.version']).toBe('2.1.0') + expect(buildTracesResourceAttributes(config(), 'posthog-node', '1.0.0')).not.toHaveProperty( + 'deployment.environment' + ) + }) + + it('protects SDK identity keys from user resource attributes', () => { + const attributes = buildTracesResourceAttributes( + config({ resourceAttributes: { 'telemetry.sdk.name': 'custom', 'host.name': 'web-01' } }), + 'posthog-node', + '1.0.0' + ) + expect(attributes['telemetry.sdk.name']).toBe('posthog-node') + expect(attributes['host.name']).toBe('web-01') + }) + }) + + describe('buildOtlpTracesPayload', () => { + it('produces one resource, one scope, N spans', () => { + const spans = [buildOtlpSpan(record()), buildOtlpSpan(record({ name: 'other' }))] + const payload = buildOtlpTracesPayload(spans, { 'service.name': 'checkout' }, 'posthog-node', '1.0.0') + + expect(payload.resourceSpans).toHaveLength(1) + expect(payload.resourceSpans[0].scopeSpans).toHaveLength(1) + expect(payload.resourceSpans[0].scopeSpans[0].spans).toHaveLength(2) + expect(payload.resourceSpans[0].scopeSpans[0].scope).toEqual({ name: 'posthog-node', version: '1.0.0' }) + expect(payload.resourceSpans[0].resource.attributes).toEqual([ + { key: 'service.name', value: { stringValue: 'checkout' } }, + ]) + }) + }) + + describe('golden wire fixture', () => { + it('matches the shape the ingestion service accepts', () => { + // Pinned against the OTLP/JSON encoding the capture-logs service's own + // trace fixtures use: hex ids, string nanosecond timestamps, integer kind + // and status enums, and stringified int64 attribute values. + const payload = buildOtlpTracesPayload( + [ + buildOtlpSpan( + record({ + parentSpanId: 'b7ad6b7169203331', + name: 'GET /users/:id', + kind: 'server', + status: { code: 'error', message: 'boom' }, + attributes: { + posthogDistinctId: 'user-123', + sessionId: 'session-123', + 'http.status_code': 500, + 'http.duration_ratio': 0.25, + cached: false, + }, + events: [ + { + name: 'exception', + timestamp: 1_700_000_000_040, + attributes: { 'exception.type': 'TypeError', 'exception.message': 'boom' }, + }, + ], + }) + ), + ], + { 'service.name': 'checkout-api', 'telemetry.sdk.name': 'posthog-node' }, + 'posthog-node', + '1.0.0' + ) + + expect(payload).toEqual({ + resourceSpans: [ + { + resource: { + attributes: [ + { key: 'service.name', value: { stringValue: 'checkout-api' } }, + { key: 'telemetry.sdk.name', value: { stringValue: 'posthog-node' } }, + ], + }, + scopeSpans: [ + { + scope: { name: 'posthog-node', version: '1.0.0' }, + spans: [ + { + traceId: '4bf92f3577b34da6a3ce929d0e0e4736', + spanId: '00f067aa0ba902b7', + parentSpanId: 'b7ad6b7169203331', + name: 'GET /users/:id', + kind: 2, + startTimeUnixNano: '1700000000000000000', + endTimeUnixNano: '1700000000080000000', + flags: 1, + attributes: [ + { key: 'posthogDistinctId', value: { stringValue: 'user-123' } }, + { key: 'sessionId', value: { stringValue: 'session-123' } }, + { key: 'http.status_code', value: { intValue: '500' } }, + { key: 'http.duration_ratio', value: { doubleValue: 0.25 } }, + { key: 'cached', value: { boolValue: false } }, + ], + events: [ + { + name: 'exception', + timeUnixNano: '1700000000040000000', + attributes: [ + { key: 'exception.type', value: { stringValue: 'TypeError' } }, + { key: 'exception.message', value: { stringValue: 'boom' } }, + ], + }, + ], + status: { code: 2, message: 'boom' }, + }, + ], + }, + ], + }, + ], + }) + }) + }) +}) diff --git a/packages/core/src/traces/otlp.ts b/packages/core/src/traces/otlp.ts new file mode 100644 index 0000000000..cab5cf32c4 --- /dev/null +++ b/packages/core/src/traces/otlp.ts @@ -0,0 +1,168 @@ +// OTLP encoding for spans. +// +// Attribute values go through the shared `AnyValue` encoder, which is what the +// logs and metrics senders use: the wire shape is the same for all three, and +// the guards that keep a single bad value from 400ing an entire batch are worth +// having in one place. + +import type { + OtlpSpan, + OtlpSpanEvent, + OtlpSpanKeyValue, + OtlpTracesPayload, + SpanAttributes, + SpanKind, + SpanStatusCode, +} from '@posthog/types' +import type { Logger } from '../types' +import type { ResolvedTracesConfig, SpanRecord } from './types' +import { toOtlpKeyValueList } from '../utils/otlp-any-value' + +// ============================================================================ +// Enums +// ============================================================================ + +const SPAN_KIND_TO_OTLP: Record = { + internal: 1, + server: 2, + client: 3, + producer: 4, + consumer: 5, +} + +const SPAN_STATUS_TO_OTLP: Record = { + ok: 1, + error: 2, +} + +/** W3C trace flags: the sampled bit, always set because v1 records every captured span. */ +const TRACE_FLAGS_SAMPLED = 1 + +export function spanKindToOtlp(kind: SpanKind | undefined): number { + return (kind && SPAN_KIND_TO_OTLP[kind]) || SPAN_KIND_TO_OTLP.internal +} + +// ============================================================================ +// Timestamps +// ============================================================================ + +/** + * Converts a millisecond epoch to the unix-nanosecond string OTLP expects. + * + * Concatenation rather than multiplication: `Date.now() * 1e6` exceeds + * `Number.MAX_SAFE_INTEGER` and would lose precision. + */ +export function msToUnixNanoString(ms: number): string { + let whole = Math.floor(ms) + let fractionalNanos = Math.round((ms - whole) * 1e6) + // Rounding can carry into the next millisecond. Without this the padded + // fraction gains a seventh digit and the concatenated timestamp is malformed, + // which 400s the entire request — the exact failure client-side validity + // exists to prevent. + if (fractionalNanos >= 1e6) { + whole += 1 + fractionalNanos = 0 + } + return String(whole) + String(fractionalNanos).padStart(6, '0') +} + +// ============================================================================ +// Span and envelope construction +// ============================================================================ + +function toOtlpEvent(event: SpanRecord['events'][number], logger?: Logger): OtlpSpanEvent { + const encoded: OtlpSpanEvent = { + name: event.name, + timeUnixNano: msToUnixNanoString(event.timestamp), + } + if (event.attributes) { + const attributes = toOtlpKeyValueList(event.attributes, logger) + if (attributes.length) { + encoded.attributes = attributes + } + } + return encoded +} + +export function buildOtlpSpan(record: SpanRecord, logger?: Logger): OtlpSpan { + const span: OtlpSpan = { + traceId: record.traceId, + spanId: record.spanId, + name: record.name, + kind: spanKindToOtlp(record.kind), + startTimeUnixNano: msToUnixNanoString(record.startTime), + endTimeUnixNano: msToUnixNanoString(record.endTime), + flags: TRACE_FLAGS_SAMPLED, + } + if (record.parentSpanId) { + span.parentSpanId = record.parentSpanId + } + if (record.traceState) { + span.traceState = record.traceState + } + const attributes = toOtlpKeyValueList(record.attributes, logger) + if (attributes.length) { + span.attributes = attributes + } + if (record.events.length) { + span.events = record.events.map((event) => toOtlpEvent(event, logger)) + } + // An unset status is omitted rather than sent as code 0 — the server treats + // both the same, and omitting keeps the payload honest about "never set". + if (record.status) { + span.status = { + code: SPAN_STATUS_TO_OTLP[record.status.code], + ...(record.status.message && { message: record.status.message }), + } + } + return span +} + +/** + * OTLP resource attributes for every batch. + * + * User `resourceAttributes` are spread first, then SDK-controlled identity keys + * on top so a stray key can't clobber them. `service.name` is always emitted: + * the server reads `service_name` only from that attribute and stores an empty + * string when it's missing, leaving spans unattributable in the product. + */ +export function buildTracesResourceAttributes( + config: ResolvedTracesConfig, + sdkName: string, + sdkVersion: string +): SpanAttributes { + return { + ...config.resourceAttributes, + 'service.name': config.serviceName || 'unknown_service', + ...(config.environment && { 'deployment.environment': config.environment }), + ...(config.serviceVersion && { 'service.version': config.serviceVersion }), + 'telemetry.sdk.name': sdkName, + 'telemetry.sdk.version': sdkVersion, + } +} + +/** + * Wraps spans in the OTLP `resourceSpans` envelope: one resource, one scope, N + * spans per batch. The server flattens the scope to `{name}@{version}`. + */ +export function buildOtlpTracesPayload( + spans: OtlpSpan[], + resourceAttributes: SpanAttributes, + scopeName: string, + scopeVersion: string, + logger?: Logger +): OtlpTracesPayload { + return { + resourceSpans: [ + { + resource: { attributes: toOtlpKeyValueList(resourceAttributes, logger) }, + scopeSpans: [ + { + scope: { name: scopeName, version: scopeVersion }, + spans, + }, + ], + }, + ], + } +} diff --git a/packages/core/src/traces/sanitize.ts b/packages/core/src/traces/sanitize.ts new file mode 100644 index 0000000000..a3fd1b7def --- /dev/null +++ b/packages/core/src/traces/sanitize.ts @@ -0,0 +1,110 @@ +// Client-side validity. +// +// The ingestion service 400s the *entire request* when one span fails row +// conversion — a timestamp that doesn't fit signed 64-bit nanoseconds, say — and +// a 400 is non-retriable poison. One bad span therefore silently destroys every +// other span in the batch, which is why sanitizing before enqueue is the SDK's +// job rather than something we lean on server tolerance for. + +import type { Logger } from '../types' +import type { SpanTimeInput } from '@posthog/types' + +const FALLBACK_SPAN_NAME = 'unknown' + +// OTLP declares the timestamp fields `fixed64`, but the service parses them as +// signed 64-bit, so a negative (pre-epoch) value is as invalid as an overflow. +// Expressed in milliseconds, since that's the unit the SDK works in. +const MAX_TIMESTAMP_MS = 9223372036854 // floor(i64::MAX nanoseconds / 1e6) +const MIN_TIMESTAMP_MS = 0 + +// The server clamps timestamps more than 24h from receive time to now, keeping +// the original in `$originalTimestamp`. Worth a warning: the span survives, but +// not where the caller put it on the timeline. +const DEEP_BACKDATE_WARNING_MS = 24 * 60 * 60 * 1000 + +/** + * Span and event names must be non-empty. An empty or non-string name is + * replaced rather than dropped, so a mis-instrumented call site loses its name, + * not its span. + * + * `label` names what is being sanitized in the warning ("Span name", "Span event + * name"), so the diagnostic points at the call the caller actually made. + */ +export function sanitizeName(name: unknown, label: string, logger?: Logger): string { + if (typeof name === 'string' && name.trim()) { + return name + } + logger?.debug(`${label} must be a non-empty string; using "${FALLBACK_SPAN_NAME}"`) + return FALLBACK_SPAN_NAME +} + +/** + * Normalizes a caller-supplied time to a millisecond epoch. + * + * Returns `undefined` for anything unusable — the wrong type, `NaN`, or outside + * the representable range — leaving the caller to fall back to a derived time. + */ +export function toEpochMs(value: SpanTimeInput | undefined): number | undefined { + if (value === undefined || value === null) { + return undefined + } + const ms = value instanceof Date ? value.getTime() : value + if (typeof ms !== 'number' || !Number.isFinite(ms)) { + return undefined + } + if (ms < MIN_TIMESTAMP_MS || ms > MAX_TIMESTAMP_MS) { + return undefined + } + return ms +} + +/** + * Resolves a caller-supplied start time, warning when it is deep enough in the + * past that the server will clamp it. + */ +export function resolveStartTime(value: SpanTimeInput | undefined, now: number, logger?: Logger): number { + const supplied = toEpochMs(value) + if (supplied === undefined) { + if (value !== undefined) { + logger?.debug('Span startTime is out of range or not a valid time; using the current time') + } + return now + } + if (now - supplied > DEEP_BACKDATE_WARNING_MS) { + 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' + ) + } + return supplied +} + +/** + * Corrects an end time that precedes its start, producing a zero-duration span + * rather than a negative one the server would reject. + */ +export function clampEndTime(endTime: number, startTime: number): number { + return endTime < startTime ? startTime : endTime +} + +/** + * Keeps a caller-supplied end or event time inside the representable range, + * falling back to the span's own clock basis when it is unusable. + * + * `label` names what is being sanitized in the warning ("end time", "event + * timestamp"), so the diagnostic points at the call the caller actually made. + */ +export function resolveSuppliedTime( + value: SpanTimeInput | undefined, + derived: number, + label: string, + logger?: Logger +): number { + const supplied = toEpochMs(value) + if (supplied === undefined) { + if (value !== undefined) { + logger?.debug(`Span ${label} is out of range or not a valid time; using the derived time`) + } + return derived + } + return supplied +} diff --git a/packages/core/src/traces/span.spec.ts b/packages/core/src/traces/span.spec.ts new file mode 100644 index 0000000000..33bf719061 --- /dev/null +++ b/packages/core/src/traces/span.spec.ts @@ -0,0 +1,262 @@ +import { NOOP_SPAN, PostHogSpan, describeError } from './span' +import type { SpanInit } from './span' +import type { SpanRecord } from './types' +import type { Logger } from '../types' +import { createMockLogger } from '@/testing' + +const TRACE_ID = '4bf92f3577b34da6a3ce929d0e0e4736' +const SPAN_ID = '00f067aa0ba902b7' + +describe('PostHogSpan', () => { + let ended: SpanRecord[] + let logger: Logger + + const createSpan = (init: Partial = {}): PostHogSpan => + new PostHogSpan( + { + traceId: TRACE_ID, + spanId: SPAN_ID, + name: 'checkout', + kind: 'internal', + attributes: {}, + startTime: Date.now(), + backdated: false, + ...init, + }, + (record) => ended.push(record), + logger + ) + + beforeEach(() => { + ended = [] + logger = createMockLogger() + }) + + it('produces exactly one record on end', () => { + createSpan().end() + expect(ended).toHaveLength(1) + expect(ended[0].name).toBe('checkout') + }) + + it('is idempotent on end', () => { + const span = createSpan() + span.end() + span.end() + expect(ended).toHaveLength(1) + }) + + it('ignores operations after end', () => { + const span = createSpan() + span.end() + span.setAttribute('k', 'v') + span.updateName('renamed') + span.addEvent('late') + + expect(ended[0].attributes).not.toHaveProperty('k') + expect(ended[0].name).toBe('checkout') + expect(ended[0].events).toHaveLength(0) + }) + + it('chains mutators', () => { + const span = createSpan() + span.setAttribute('a', 1).setAttributes({ b: 2 }).setStatus('ok').updateName('renamed') + span.end() + + expect(ended[0].attributes).toEqual({ a: 1, b: 2 }) + expect(ended[0].name).toBe('renamed') + expect(ended[0].status).toEqual({ code: 'ok' }) + }) + + it('replaces the name up until end', () => { + // A route template is often only knowable after routing resolves, and the + // product aggregates by (service, name) — so renaming has to be possible. + const span = createSpan({ name: 'HTTP request' }) + span.updateName('GET /users/:id') + span.end() + expect(ended[0].name).toBe('GET /users/:id') + }) + + it('replaces an empty name rather than dropping the span', () => { + const span = createSpan() + span.updateName(' ') + span.end() + expect(ended[0].name).toBe('unknown') + }) + + it('applies last-write-wins to status', () => { + const span = createSpan() + span.setStatus('ok') + span.setStatus('error', 'boom') + span.end() + expect(ended[0].status).toEqual({ code: 'error', message: 'boom' }) + }) + + it('omits status when never set', () => { + createSpan().end() + expect(ended[0].status).toBeUndefined() + }) + + describe('recordException', () => { + it('sets error status and attaches an exception event without ending', () => { + const span = createSpan() + span.recordException(new TypeError('boom')) + + expect(ended).toHaveLength(0) + + span.end() + expect(ended[0].status).toEqual({ code: 'error', message: 'boom' }) + expect(ended[0].events).toEqual([ + expect.objectContaining({ + name: 'exception', + attributes: { 'exception.type': 'TypeError', 'exception.message': 'boom' }, + }), + ]) + }) + }) + + describe('timestamps', () => { + it('records an end at or after the start', () => { + const span = createSpan() + span.end() + expect(ended[0].endTime).toBeGreaterThanOrEqual(ended[0].startTime) + }) + + it('honours an explicit end time', () => { + const start = 1_700_000_000_000 + const span = createSpan({ startTime: start, backdated: true }) + span.end(start + 5000) + expect(ended[0].endTime).toBe(start + 5000) + }) + + it('accepts a Date as an end time', () => { + const start = 1_700_000_000_000 + const span = createSpan({ startTime: start, backdated: true }) + span.end(new Date(start + 1000)) + expect(ended[0].endTime).toBe(start + 1000) + }) + + it('corrects an end before the start to a zero duration', () => { + const start = 1_700_000_000_000 + const span = createSpan({ startTime: start, backdated: true }) + span.end(start - 5000) + expect(ended[0].endTime).toBe(start) + }) + + it('falls back to the derived end for an out-of-range end time', () => { + const start = 1_700_000_000_000 + const span = createSpan({ startTime: start, backdated: true }) + span.end(Number.MAX_SAFE_INTEGER) + expect(ended[0].endTime).toBeGreaterThanOrEqual(start) + expect(ended[0].endTime).toBeLessThan(9_223_372_036_854) + }) + + it('keeps event timestamps inside the span window', () => { + const span = createSpan() + span.addEvent('cache miss') + span.end() + + const [event] = ended[0].events + expect(event.timestamp).toBeGreaterThanOrEqual(ended[0].startTime) + expect(event.timestamp).toBeLessThanOrEqual(ended[0].endTime) + }) + + it('honours an explicit event timestamp', () => { + const start = 1_700_000_000_000 + const span = createSpan({ startTime: start, backdated: true }) + span.addEvent('cache miss', undefined, start + 40) + span.end(start + 80) + expect(ended[0].events[0].timestamp).toBe(start + 40) + }) + + it('snapshots event attributes so a reused object cannot mutate them', () => { + const span = createSpan() + const reused = { attempt: 1 } + span.addEvent('retry', reused) + reused.attempt = 2 + span.addEvent('retry', reused) + span.end() + + expect(ended[0].events.map((event) => event.attributes)).toEqual([{ attempt: 1 }, { attempt: 2 }]) + }) + }) + + describe('context propagation', () => { + it('produces a sampled traceparent', () => { + expect(createSpan().traceparent()).toBe(`00-${TRACE_ID}-${SPAN_ID}-01`) + }) + + it('returns null tracestate when it has none', () => { + expect(createSpan().tracestate()).toBeNull() + }) + + it('returns the tracestate it was created with', () => { + expect(createSpan({ traceState: 'vendor=abc' }).tracestate()).toBe('vendor=abc') + }) + + it('exposes a child context carrying its own span id as the parent', () => { + expect(createSpan({ traceState: 'vendor=abc' }).childContext()).toEqual({ + traceId: TRACE_ID, + parentSpanId: SPAN_ID, + traceState: 'vendor=abc', + }) + }) + }) +}) + +describe('NoopSpan', () => { + it('supports the full surface without throwing', () => { + expect(() => { + NOOP_SPAN.setAttribute('a', 1) + .setAttributes({ b: 2 }) + .addEvent('x') + .setStatus('error', 'boom') + .recordException(new Error('boom')) + .updateName('renamed') + .end() + }).not.toThrow() + }) + + it('never produces a well-formed traceparent', () => { + // An id that was never recorded must not propagate to another service. + expect(NOOP_SPAN.traceparent()).toBeNull() + expect(NOOP_SPAN.tracestate()).toBeNull() + }) +}) + +describe('describeError', () => { + it.each([ + ['an Error', new Error('boom'), { type: 'Error', message: 'boom' }], + ['a TypeError', new TypeError('bad type'), { type: 'TypeError', message: 'bad type' }], + ['a string', 'just a string', { type: 'string', message: 'just a string' }], + ['an object with a message', { name: 'CustomError', message: 'oops' }, { type: 'CustomError', message: 'oops' }], + ['an object without a name', { message: 'oops' }, { type: 'Object', message: 'oops' }], + ])('describes %s', (_name, error, expected) => { + expect(describeError(error)).toEqual(expected) + }) + + it('describes a thrown primitive', () => { + // Anything can be thrown in JS, so a non-Error must still produce a usable + // exception event rather than being dropped. + expect(describeError(42)).toEqual({ type: 'number', message: '42' }) + }) + + it('survives a value whose toString throws', () => { + const hostile = { + message: 123, + toString() { + throw new Error('boom from toString') + }, + } + expect(() => describeError(hostile)).not.toThrow() + expect(describeError(hostile)).toEqual({ type: 'object', message: '' }) + }) + + it('survives a value whose message getter throws', () => { + const hostile = { + get message(): string { + throw new Error('boom from getter') + }, + } + expect(() => describeError(hostile)).not.toThrow() + }) +}) diff --git a/packages/core/src/traces/span.ts b/packages/core/src/traces/span.ts new file mode 100644 index 0000000000..53781701f2 --- /dev/null +++ b/packages/core/src/traces/span.ts @@ -0,0 +1,258 @@ +import type { Span, SpanAttributes, SpanAttributeValue, SpanKind, SpanStatusCode, SpanTimeInput } from '@posthog/types' +import type { Logger } from '../types' +import type { SpanEventRecord, SpanRecord } from './types' +import { formatTraceparent } from './traceparent' +import { clampEndTime, resolveSuppliedTime, sanitizeName } from './sanitize' +import { isError } from '../utils' + +/** + * A monotonic millisecond reading where the platform has one. + * + * Durations are measured against this rather than the wall clock so an NTP + * correction mid-span can't produce a negative duration, and so event + * timestamps provably land inside the span window. + */ +function monotonicNow(): number | undefined { + const perf = (globalThis as { performance?: { now?: () => number } }).performance + return typeof perf?.now === 'function' ? perf.now() : undefined +} + +export interface SpanInit { + traceId: string + spanId: string + parentSpanId?: string + traceState?: string + name: string + kind: SpanKind + attributes: SpanAttributes + /** ms epoch. */ + startTime: number + /** True when the caller supplied an explicit `startTime`. */ + backdated: boolean +} + +export class PostHogSpan implements Span { + private readonly _traceId: string + private readonly _spanId: string + private readonly _parentSpanId?: string + private readonly _traceState?: string + private readonly _startTime: number + // Monotonic reading at construction, absent on backdated spans (which use the + // wall clock throughout) and on platforms with no monotonic source. + private readonly _startMono?: number + + private _name: string + private _kind: SpanKind + private _attributes: SpanAttributes + private _events: SpanEventRecord[] = [] + private _status?: { code: SpanStatusCode; message?: string } + private _ended = false + + constructor( + init: SpanInit, + private readonly _onEnd: (record: SpanRecord) => void, + private readonly _logger?: Logger + ) { + this._traceId = init.traceId + this._spanId = init.spanId + this._parentSpanId = init.parentSpanId + this._traceState = init.traceState + this._name = init.name + this._kind = init.kind + this._attributes = init.attributes + this._startTime = init.startTime + this._startMono = init.backdated ? undefined : monotonicNow() + } + + /** + * "Now" on this span's clock basis: start plus monotonic elapsed where we + * have it, wall clock otherwise. + */ + private _now(): number { + if (this._startMono !== undefined) { + const mono = monotonicNow() + if (mono !== undefined) { + return this._startTime + Math.max(0, mono - this._startMono) + } + } + return Date.now() + } + + /** Guards every mutator: operations after `end()` no-op with a debug warning. */ + private _mutable(operation: string): boolean { + if (this._ended) { + this._logger?.debug(`Ignoring ${operation} on a span that has already ended`) + return false + } + return true + } + + setAttribute(key: string, value: SpanAttributeValue): this { + if (this._mutable('setAttribute')) { + this._attributes[key] = value + } + return this + } + + setAttributes(attributes: SpanAttributes): this { + if (this._mutable('setAttributes')) { + for (const key in attributes) { + this._attributes[key] = attributes[key] + } + } + return this + } + + addEvent(name: string, attributes?: SpanAttributes, timestamp?: SpanTimeInput): this { + if (this._mutable('addEvent')) { + this._events.push({ + name: sanitizeName(name, 'Span event name', this._logger), + timestamp: resolveSuppliedTime(timestamp, this._now(), 'event timestamp', this._logger), + // Copied so a caller reusing one object across events can't mutate a recorded one. + ...(attributes && { attributes: { ...attributes } }), + }) + } + return this + } + + setStatus(status: SpanStatusCode, message?: string): this { + if (this._mutable('setStatus')) { + this._status = { code: status, ...(message && { message }) } + } + return this + } + + /** True when the caller explicitly marked the span `ok`; `withSpan` treats that as final. */ + get statusIsExplicitlyOk(): boolean { + return this._status?.code === 'ok' + } + + recordException(error: unknown): this { + if (!this._mutable('recordException')) { + return this + } + const { type, message } = describeError(error) + this.addEvent('exception', { + 'exception.type': type, + 'exception.message': message, + }) + // recordException is itself an explicit call, so it follows last-write-wins + // rather than deferring to an earlier `ok`. + return this.setStatus('error', message) + } + + updateName(name: string): this { + if (this._mutable('updateName')) { + this._name = sanitizeName(name, 'Span name', this._logger) + } + return this + } + + traceparent(): string | null { + return formatTraceparent(this._traceId, this._spanId) + } + + tracestate(): string | null { + return this._traceState ?? null + } + + /** Context a child span inherits when this handle is its parent. */ + childContext(): { traceId: string; parentSpanId: string; traceState?: string } { + return { traceId: this._traceId, parentSpanId: this._spanId, traceState: this._traceState } + } + + end(endTime?: SpanTimeInput): void { + if (this._ended) { + this._logger?.debug('Ignoring end() on a span that has already ended') + return + } + this._ended = true + + const derived = this._now() + const resolved = resolveSuppliedTime(endTime, derived, 'end time', this._logger) + + this._onEnd({ + traceId: this._traceId, + spanId: this._spanId, + ...(this._parentSpanId && { parentSpanId: this._parentSpanId }), + ...(this._traceState && { traceState: this._traceState }), + name: this._name, + kind: this._kind, + ...(this._status && { status: this._status }), + attributes: this._attributes, + events: this._events, + startTime: this._startTime, + endTime: clampEndTime(resolved, this._startTime), + }) + } +} + +/** + * An inert handle returned whenever tracing cannot run — traces unconfigured, + * SDK disabled, user opted out. + * + * It supports the full surface so caller code never branches, is never + * activated, and returns `null` from `traceparent()` so an id that was never + * recorded cannot propagate to another service. + */ +export class NoopSpan implements Span { + setAttribute(): this { + return this + } + setAttributes(): this { + return this + } + addEvent(): this { + return this + } + setStatus(): this { + return this + } + recordException(): this { + return this + } + updateName(): this { + return this + } + traceparent(): string | null { + return null + } + tracestate(): string | null { + return null + } + end(): void { + // Nothing to end. + } +} + +// Typed as `Span`, not `NoopSpan`: the class's methods take no parameters (they +// ignore everything), so the concrete type would reject calls the interface +// allows. Nothing should depend on the concrete class. +export const NOOP_SPAN: Span = new NoopSpan() + +/** + * Extracts the OTel `exception.type` / `exception.message` pair from whatever the + * application threw. Anything can be thrown in JS, so non-Errors are described + * by their primitive type rather than dropped. + */ +export function describeError(error: unknown): { type: string; message: string } { + try { + if (isError(error)) { + return { type: error.name || 'Error', message: error.message || '' } + } + if (typeof error === 'string') { + return { type: 'string', message: error } + } + if (error && typeof error === 'object') { + const maybe = error as { name?: unknown; message?: unknown } + if (typeof maybe.message === 'string') { + return { type: typeof maybe.name === 'string' ? maybe.name : 'Object', message: maybe.message } + } + } + return { type: typeof error, message: String(error) } + } catch { + // A hostile `toString` or accessor must not throw a second error: in `withSpan` + // that would replace the application's error and skip the span's `end()`. + return { type: typeof error, message: '' } + } +} diff --git a/packages/core/src/traces/traceparent.spec.ts b/packages/core/src/traces/traceparent.spec.ts new file mode 100644 index 0000000000..fa06931510 --- /dev/null +++ b/packages/core/src/traces/traceparent.spec.ts @@ -0,0 +1,77 @@ +import { formatTraceparent, parseTraceparent, sanitizeTracestate } from './traceparent' + +const TRACE_ID = '4bf92f3577b34da6a3ce929d0e0e4736' +const SPAN_ID = '00f067aa0ba902b7' + +describe('traceparent', () => { + describe('parseTraceparent', () => { + it('parses a sampled header', () => { + expect(parseTraceparent(`00-${TRACE_ID}-${SPAN_ID}-01`)).toEqual({ traceId: TRACE_ID, spanId: SPAN_ID }) + }) + + it('continues the trace even when the caller sampled it out', () => { + // We record every captured span in v1, so honouring an inbound `00` would + // orphan our own spans rather than save anything. + expect(parseTraceparent(`00-${TRACE_ID}-${SPAN_ID}-00`)).toEqual({ traceId: TRACE_ID, spanId: SPAN_ID }) + }) + + it('accepts a future version with extra fields', () => { + expect(parseTraceparent(`01-${TRACE_ID}-${SPAN_ID}-01-something`)).toEqual({ + traceId: TRACE_ID, + spanId: SPAN_ID, + }) + }) + + it('normalizes case and surrounding whitespace', () => { + expect(parseTraceparent(` 00-${TRACE_ID.toUpperCase()}-${SPAN_ID.toUpperCase()}-01 `)).toEqual({ + traceId: TRACE_ID, + spanId: SPAN_ID, + }) + }) + + it.each([ + ['garbage', 'garbage'], + ['an empty string', ''], + ['version ff', `ff-${TRACE_ID}-${SPAN_ID}-01`], + ['an all-zero trace id', `00-${'0'.repeat(32)}-${SPAN_ID}-01`], + ['an all-zero span id', `00-${TRACE_ID}-${'0'.repeat(16)}-01`], + ['a short trace id', `00-abc-${SPAN_ID}-01`], + ['a missing field', `00-${TRACE_ID}-${SPAN_ID}`], + ['a non-string', 42], + ['undefined', undefined], + ])('returns undefined for %s', (_name, value) => { + expect(parseTraceparent(value)).toBeUndefined() + }) + }) + + describe('formatTraceparent', () => { + it('always sets the sampled flag', () => { + expect(formatTraceparent(TRACE_ID, SPAN_ID)).toBe(`00-${TRACE_ID}-${SPAN_ID}-01`) + }) + + it('round-trips through the parser', () => { + expect(parseTraceparent(formatTraceparent(TRACE_ID, SPAN_ID))).toEqual({ traceId: TRACE_ID, spanId: SPAN_ID }) + }) + }) + + describe('sanitizeTracestate', () => { + it('preserves a valid vendor list unchanged', () => { + expect(sanitizeTracestate('vendor=abc,other=def')).toBe('vendor=abc,other=def') + }) + + it('trims surrounding whitespace', () => { + expect(sanitizeTracestate(' vendor=abc ')).toBe('vendor=abc') + }) + + it.each([ + ['an empty string', ''], + ['a member without a value', 'vendor'], + ['a non-string', 42], + ['undefined', undefined], + ['more than 32 members', Array.from({ length: 33 }, (_v, i) => `k${i}=v`).join(',')], + ['an overlong value', `vendor=${'a'.repeat(600)}`], + ])('discards %s', (_name, value) => { + expect(sanitizeTracestate(value)).toBeUndefined() + }) + }) +}) diff --git a/packages/core/src/traces/traceparent.ts b/packages/core/src/traces/traceparent.ts new file mode 100644 index 0000000000..de89d34c4a --- /dev/null +++ b/packages/core/src/traces/traceparent.ts @@ -0,0 +1,86 @@ +// W3C Trace Context header serialization. +// +// The traceparent string is the interchange format for span context — there is +// no separate context type in the public API. `parent` accepts either a span +// handle or one of these strings. + +import { isValidSpanId, isValidTraceId } from './ids' + +export interface RemoteSpanContext { + traceId: string + spanId: string +} + +// `00-<32 hex>-<16 hex>-<2 hex>`. Version `ff` is invalid per the spec; other +// unknown versions are forwards-compatible, so we parse the first four fields +// and ignore any the future adds. +const TRACEPARENT_RE = /^([0-9a-f]{2})-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})(-.*)?$/ + +/** + * Parses an incoming `traceparent` header value. + * + * Returns `undefined` for anything malformed, so a bad header starts a fresh + * root trace rather than throwing into application code. + * + * Incoming trace flags are deliberately ignored: we continue the trace even + * when the caller sampled it out (`00`), because PostHog records every captured + * span in v1 and dropping the parentage would orphan our own spans. + */ +export function parseTraceparent(value: unknown): RemoteSpanContext | undefined { + if (typeof value !== 'string') { + return undefined + } + const match = TRACEPARENT_RE.exec(value.trim().toLowerCase()) + if (!match) { + return undefined + } + const [, version, traceId, spanId] = match + if (version === 'ff') { + return undefined + } + if (!isValidTraceId(traceId) || !isValidSpanId(spanId)) { + return undefined + } + return { traceId, spanId } +} + +/** + * Builds the `traceparent` header value for a span. The sampled flag is always + * set, because a span we exported is by definition recorded. + */ +export function formatTraceparent(traceId: string, spanId: string): string { + return `00-${traceId}-${spanId}-01` +} + +// tracestate is a comma-separated list of at most 32 `key=value` members, and +// is carried opaquely — we never interpret the vendor entries. +const TRACESTATE_MAX_MEMBERS = 32 +const TRACESTATE_MAX_LENGTH = 512 + +/** + * Validates an incoming `tracestate` far enough to know it is safe to echo back. + * + * An invalid tracestate is discarded without invalidating its traceparent, so a + * malformed vendor entry never costs us the trace continuation. + */ +export function sanitizeTracestate(value: unknown): string | undefined { + if (typeof value !== 'string') { + return undefined + } + const trimmed = value.trim() + if (!trimmed || trimmed.length > TRACESTATE_MAX_LENGTH) { + return undefined + } + const members = trimmed.split(',') + if (members.length > TRACESTATE_MAX_MEMBERS) { + return undefined + } + for (const member of members) { + // An empty member is tolerated by the spec (list optional-white-space), but + // a member without a `=` is not a key/value pair at all. + if (member.trim() && !member.includes('=')) { + return undefined + } + } + return trimmed +} diff --git a/packages/core/src/traces/types.ts b/packages/core/src/traces/types.ts new file mode 100644 index 0000000000..f5e75b9ed0 --- /dev/null +++ b/packages/core/src/traces/types.ts @@ -0,0 +1,115 @@ +// Re-export the user-facing tracing types from @posthog/types so the rest of the +// traces module can pull everything from one place. +export type { + Span, + SpanAttributes, + SpanAttributeValue, + SpanKind, + SpanStatusCode, + SpanTimeInput, + StartSpanOptions, + TracesConfig, + OtlpSpan, + OtlpSpanAnyValue, + OtlpSpanEvent, + OtlpSpanKeyValue, + OtlpSpanStatus, + OtlpTracesPayload, +} from '@posthog/types' + +import type { OtlpTracesPayload, Span, SpanAttributes, SpanKind, SpanStatusCode, TracesConfig } from '@posthog/types' + +/** Same tagged outcome shape as `SendLogsBatchOutcome` — one policy for all three signals. */ +export type SendTracesBatchOutcome = + | { kind: 'ok' } + | { kind: 'retry-later'; error: unknown } + | { kind: 'too-large' } + | { kind: 'fatal'; error: unknown } + +/** + * The minimal host surface `PostHogTraces` depends on. `PostHogCoreStateless` + * satisfies it structurally (node, mobile); the browser supplies an adapter + * backed by its own request layer. + */ +export interface TracesHost { + readonly isDisabled: boolean + readonly optedOut: boolean + _sendTracesBatch(payload: OtlpTracesPayload): Promise + getLibraryId(): string + getLibraryVersion(): string +} + +/** + * PostHog context snapshotted onto every span at start, so traces join back to + * persons and sessions. Each SDK fills the fields that apply to it: server SDKs + * read their request context, client SDKs their process-global identity and + * session manager. Absent fields add no attribute. + * + * Internal to `@posthog/core` — customers don't see this in autocomplete. + */ +export interface TraceSdkContext { + distinctId?: string + sessionId?: string + /** Web-only — current page URL. */ + currentUrl?: string + /** Mobile-only — current screen / view name. */ + screenName?: string + /** Mobile-only — app foreground/background state. */ + appState?: 'foreground' | 'background' +} + +export interface SpanEventRecord { + name: string + /** ms epoch. */ + timestamp: number + attributes?: SpanAttributes +} + +/** + * A completed span in plain, pre-encoding form: strings for kind and status, a + * plain attribute map, ms-epoch timestamps. This is what the engine queues. + */ +export interface SpanRecord { + traceId: string + spanId: string + parentSpanId?: string + traceState?: string + name: string + kind: SpanKind + status?: { code: SpanStatusCode; message?: string } + attributes: SpanAttributes + events: SpanEventRecord[] + /** ms epoch. */ + startTime: number + endTime: number +} + +/** + * Tracks which span is active, so spans nest without manual parent plumbing. + * + * The mechanism is platform-specific and stays out of core: node injects an + * `AsyncLocalStorage` implementation, the browser a synchronous one. Core must + * not import `node:async_hooks` — it ships to browsers, edge runtimes and + * React Native. + */ +export interface SpanContextManager { + /** The active span, or `undefined` when none is active. */ + active(): Span | undefined + /** Run `fn` with `span` active for its (synchronous and async) duration. */ + with(span: Span, fn: () => T): T +} + +/** + * Fields `PostHogTraces` needs resolved at runtime. The host SDK applies its own + * defaults and hands the resolved config to the constructor. + */ +export interface ResolvedTracesConfig extends TracesConfig { + flushIntervalMs: number + maxExportBatchSize: number + /** + * Bound on the in-memory export queue, set by the host. On overflow the + * *incoming* span is dropped rather than evicting queued ones, whose children + * may already have been exported. + */ + maxQueueSize: number +} diff --git a/packages/core/src/utils/otlp-any-value.spec.ts b/packages/core/src/utils/otlp-any-value.spec.ts new file mode 100644 index 0000000000..60bd9c9039 --- /dev/null +++ b/packages/core/src/utils/otlp-any-value.spec.ts @@ -0,0 +1,361 @@ +import type { LogAttributeValue } from '@posthog/types' +import { toOtlpAnyValue, toOtlpKeyValueList } from './otlp-any-value' + +describe('otlp-any-value', () => { + describe('toOtlpAnyValue', () => { + it('converts strings', () => { + expect(toOtlpAnyValue('hello')).toEqual({ stringValue: 'hello' }) + }) + + it('converts integers to decimal strings', () => { + expect(toOtlpAnyValue(42)).toEqual({ intValue: '42' }) + expect(toOtlpAnyValue(0)).toEqual({ intValue: '0' }) + expect(toOtlpAnyValue(-7)).toEqual({ intValue: '-7' }) + }) + + // Spec: outside int64 it is a stringValue, never an intValue. + it('converts integers outside int64 to stringValue', () => { + expect(toOtlpAnyValue(2 ** 63)).toEqual({ stringValue: '9223372036854775808' }) + expect(toOtlpAnyValue(-(2 ** 64))).toEqual({ stringValue: '-18446744073709551616' }) + expect(toOtlpAnyValue(1e21)).toEqual({ stringValue: '1000000000000000000000' }) + }) + + it('logs a debug line when an integer falls outside int64', () => { + const logger = { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn(), critical: jest.fn() } + toOtlpAnyValue(2 ** 63, logger as any) + expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('outside the int64 range')) + }) + + it('keeps int64 min as intValue', () => { + // In range, but `String` renders it 192 below int64 min, so the decimal + // has to come from BigInt. + expect(toOtlpAnyValue(-(2 ** 63))).toEqual({ intValue: '-9223372036854775808' }) + }) + + it('keeps large in-range integers exact', () => { + expect(toOtlpAnyValue(Number.MAX_SAFE_INTEGER)).toEqual({ intValue: '9007199254740991' }) + // The largest double below 2^63 — no double exists between the two. + expect(toOtlpAnyValue(9223372036854774784)).toEqual({ intValue: '9223372036854774784' }) + expect(toOtlpAnyValue(2 ** 62)).toEqual({ intValue: '4611686018427387904' }) + }) + + it('converts a bigint inside int64 to a stringified intValue', () => { + // Span attributes accept bigint; a log attribute reaching here is typed + // out but still encodes correctly. + expect(toOtlpAnyValue(9007199254740993n as unknown as LogAttributeValue)).toEqual({ + intValue: '9007199254740993', + }) + }) + + it('converts a bigint beyond int64 to a string, with a warning', () => { + const logger = { debug: jest.fn() } + expect(toOtlpAnyValue(18446744073709551616n as unknown as LogAttributeValue, logger as any)).toEqual({ + stringValue: '18446744073709551616', + }) + expect(logger.debug).toHaveBeenCalled() + }) + + it('converts floats to doubleValue', () => { + expect(toOtlpAnyValue(3.14)).toEqual({ doubleValue: 3.14 }) + }) + + it('converts booleans', () => { + expect(toOtlpAnyValue(true)).toEqual({ boolValue: true }) + expect(toOtlpAnyValue(false)).toEqual({ boolValue: false }) + }) + + // JSON has no representation for non-finite floats; without explicit + // handling, JSON.stringify silently turns them into `null` and the value + // is lost server-side. + it('converts NaN to stringValue', () => { + expect(toOtlpAnyValue(NaN)).toEqual({ stringValue: 'NaN' }) + }) + + it('converts +Infinity to stringValue', () => { + expect(toOtlpAnyValue(Infinity)).toEqual({ stringValue: 'Infinity' }) + }) + + it('converts -Infinity to stringValue', () => { + expect(toOtlpAnyValue(-Infinity)).toEqual({ stringValue: '-Infinity' }) + }) + + it('converts arrays of strings to arrayValue', () => { + expect(toOtlpAnyValue(['a', 'b'])).toEqual({ + arrayValue: { values: [{ stringValue: 'a' }, { stringValue: 'b' }] }, + }) + }) + + it('converts mixed primitive arrays recursively', () => { + expect(toOtlpAnyValue([1, 'x', true])).toEqual({ + arrayValue: { + values: [{ intValue: '1' }, { stringValue: 'x' }, { boolValue: true }], + }, + }) + }) + + it('converts plain objects to kvlistValue', () => { + expect(toOtlpAnyValue({ a: 1, b: 'two' })).toEqual({ + kvlistValue: { + values: [ + { key: 'a', value: { intValue: '1' } }, + { key: 'b', value: { stringValue: 'two' } }, + ], + }, + }) + }) + + it('converts nested objects recursively', () => { + expect(toOtlpAnyValue({ outer: { inner: 1 } })).toEqual({ + kvlistValue: { + values: [ + { + key: 'outer', + value: { kvlistValue: { values: [{ key: 'inner', value: { intValue: '1' } }] } }, + }, + ], + }, + }) + }) + + it('drops null and undefined keys inside objects', () => { + expect(toOtlpAnyValue({ kept: 1, gone: null, alsoGone: undefined })).toEqual({ + kvlistValue: { values: [{ key: 'kept', value: { intValue: '1' } }] }, + }) + }) + + // Not in LogAttributeValue, but reachable at runtime from untyped callers. + it('encodes Dates as ISO strings', () => { + expect(toOtlpAnyValue(new Date('2026-08-20T10:00:00.000Z') as unknown as LogAttributeValue)).toEqual({ + stringValue: '2026-08-20T10:00:00.000Z', + }) + }) + + it('marks circular references instead of recursing', () => { + const cyclic: Record = { name: 'root' } + cyclic.self = cyclic + expect(toOtlpAnyValue(cyclic)).toEqual({ + kvlistValue: { + values: [ + { key: 'name', value: { stringValue: 'root' } }, + { key: 'self', value: { stringValue: '[Circular]' } }, + ], + }, + }) + }) + + // An escaping error would surface in the caller's application code. + it('does not throw on an object nested past the depth cap', () => { + let deep: Record = { end: true } + for (let i = 0; i < 25000; i++) { + deep = { next: deep } + } + expect(() => toOtlpAnyValue(deep)).not.toThrow() + }) + + it('truncates at exactly 20 levels instead of recursing', () => { + let deep: Record = { end: true } + for (let i = 0; i < 25; i++) { + deep = { next: deep } + } + const encoded = JSON.stringify(toOtlpAnyValue(deep)) + expect(encoded).toContain('[Truncated]') + expect(encoded.split('"next"').length - 1).toBe(20) + }) + + it('marks a throwing getter without losing the rest of the object', () => { + const attrs = { + ok: 1, + get bad(): number { + throw new Error('getter blew up') + }, + } + expect(() => toOtlpKeyValueList(attrs)).not.toThrow() + expect(toOtlpKeyValueList(attrs)).toEqual([ + { key: 'ok', value: { intValue: '1' } }, + { key: 'bad', value: { stringValue: '[Unserializable]' } }, + ]) + }) + + // for...in walks the prototype chain once own keys are exhausted. + it('ignores inherited enumerable properties', () => { + const inherited: Record = Object.create({ fromPrototype: 'leaked' }) + inherited.own = 1 + expect(toOtlpAnyValue(inherited)).toEqual({ + kvlistValue: { values: [{ key: 'own', value: { intValue: '1' } }] }, + }) + }) + + // `String(fn)` would put the function's source text on the wire. + it('marks function and symbol values instead of stringifying them', () => { + expect(toOtlpAnyValue({ handler: () => 1, retries: 2 } as unknown as LogAttributeValue)).toEqual({ + kvlistValue: { + values: [ + { key: 'handler', value: { stringValue: '[Function]' } }, + { key: 'retries', value: { intValue: '2' } }, + ], + }, + }) + expect(toOtlpAnyValue({ sym: Symbol('x') } as unknown as LogAttributeValue)).toEqual({ + kvlistValue: { values: [{ key: 'sym', value: { stringValue: 'Symbol(x)' } }] }, + }) + }) + + // dayjs, Decimal, ORM documents. + it('honours toJSON', () => { + const wrapped = { toJSON: () => ({ amount: 5 }) } + expect(toOtlpAnyValue(wrapped as unknown as LogAttributeValue)).toEqual({ + kvlistValue: { values: [{ key: 'amount', value: { intValue: '5' } }] }, + }) + }) + + it('falls back to the plain walk when toJSON throws', () => { + const wrapped = { + kept: 1, + toJSON: () => { + throw new Error('nope') + }, + } + expect(toOtlpAnyValue(wrapped as unknown as LogAttributeValue)).toEqual({ + kvlistValue: { + values: [ + { key: 'kept', value: { intValue: '1' } }, + { key: 'toJSON', value: { stringValue: '[Function]' } }, + ], + }, + }) + }) + + // A toJSON returning its own object is a cycle like any other. + it('marks a cycle that runs through toJSON', () => { + const cyclic: Record = {} + cyclic.toJSON = () => ({ inner: cyclic }) + expect(toOtlpAnyValue(cyclic)).toEqual({ + kvlistValue: { values: [{ key: 'inner', value: { stringValue: '[Circular]' } }] }, + }) + }) + + // Both `null` and `{}` here are rejected for the whole request; iOS and + // Android drop them too. + it('drops holes and nullish elements from arrays', () => { + // eslint-disable-next-line no-sparse-arrays + expect(toOtlpAnyValue([1, , 3])).toEqual({ + arrayValue: { values: [{ intValue: '1' }, { intValue: '3' }] }, + }) + expect(toOtlpAnyValue([1, null, undefined, 3])).toEqual({ + arrayValue: { values: [{ intValue: '1' }, { intValue: '3' }] }, + }) + }) + + it('stops encoding array items once the node budget is spent', () => { + const row: Record = {} + for (let i = 0; i < 20; i++) { + row[`k${i}`] = i + } + const wide = Array.from({ length: 1000 }, () => ({ ...row })) + const values = toOtlpAnyValue(wide).arrayValue!.values + expect(values[values.length - 1]).toEqual({ stringValue: '[Truncated]' }) + // One marker, not one per unencodable item. + expect(values.filter((v) => v.stringValue === '[Truncated]')).toHaveLength(1) + }) + + it('caps a shared object graph instead of expanding it', () => { + let graph: Record = { leaf: true } + for (let i = 0; i < 20; i++) { + graph = { a: graph, b: graph } + } + const encoded = JSON.stringify(toOtlpAnyValue(graph)) + expect(encoded).toContain('[Truncated]') + expect(encoded.length).toBeLessThan(1_000_000) + }) + + it('caps a very wide object without inventing an attribute key', () => { + const wide: Record = {} + for (let i = 0; i < 5000; i++) { + wide[`k${i}`] = i + } + const logger = { debug: jest.fn(), info: jest.fn(), warn: jest.fn(), error: jest.fn(), critical: jest.fn() } + const values = toOtlpAnyValue(wide, logger as any).kvlistValue!.values + expect(values).toHaveLength(1000) + expect(values.every((v) => v.key.startsWith('k'))).toBe(true) + expect(logger.debug).toHaveBeenCalledWith(expect.stringContaining('truncated')) + }) + + // Why the encoder does not delegate to toJsonSafeValue: that maps them to null. + it('keeps non-finite floats as strings inside nested objects', () => { + expect(toOtlpAnyValue({ nested: { ratio: NaN } })).toEqual({ + kvlistValue: { + values: [ + { + key: 'nested', + value: { kvlistValue: { values: [{ key: 'ratio', value: { stringValue: 'NaN' } }] } }, + }, + ], + }, + }) + }) + + // A lone surrogate survives JSON.stringify as a \uD800 escape, which the + // server rejects for the whole request. + it('replaces unpaired surrogates in values and keys', () => { + expect(toOtlpAnyValue('ok\ud83d')).toEqual({ stringValue: 'ok\ufffd' }) + expect(toOtlpAnyValue({ nested: 'ok\ud83d' })).toEqual({ + kvlistValue: { values: [{ key: 'nested', value: { stringValue: 'ok\ufffd' } }] }, + }) + expect(toOtlpKeyValueList({ 'key\ud83d': 1 })).toEqual([{ key: 'key\ufffd', value: { intValue: '1' } }]) + }) + + it('encodes empty containers with an explicit values array', () => { + expect(toOtlpAnyValue({})).toEqual({ kvlistValue: { values: [] } }) + expect(toOtlpAnyValue([])).toEqual({ arrayValue: { values: [] } }) + }) + + it('keeps a Date whose toISOString is overridden out of the wire format', () => { + const broken = new Date('2026-08-20T10:00:00.000Z') + + ;(broken as any).toISOString = () => ({}) + expect(typeof toOtlpAnyValue(broken as unknown as LogAttributeValue).stringValue).toBe('string') + }) + + it('encodes sibling references to one object twice, not as circular', () => { + const shared = { id: 1 } + expect(toOtlpAnyValue({ a: shared, b: shared })).toEqual({ + kvlistValue: { + values: [ + { key: 'a', value: { kvlistValue: { values: [{ key: 'id', value: { intValue: '1' } }] } } }, + { key: 'b', value: { kvlistValue: { values: [{ key: 'id', value: { intValue: '1' } }] } } }, + ], + }, + }) + }) + }) + + describe('toOtlpKeyValueList', () => { + it('converts a record to key-value list', () => { + expect( + toOtlpKeyValueList({ + name: 'test', + count: 5, + active: true, + }) + ).toEqual([ + { key: 'name', value: { stringValue: 'test' } }, + { key: 'count', value: { intValue: '5' } }, + { key: 'active', value: { boolValue: true } }, + ]) + }) + + it('handles empty record', () => { + expect(toOtlpKeyValueList({})).toEqual([]) + }) + + it('skips null and undefined values', () => { + expect( + toOtlpKeyValueList({ + kept: 'yes', + nullish: null, + missing: undefined, + }) + ).toEqual([{ key: 'kept', value: { stringValue: 'yes' } }]) + }) + }) +}) diff --git a/packages/core/src/utils/otlp-any-value.ts b/packages/core/src/utils/otlp-any-value.ts new file mode 100644 index 0000000000..e84d775b1c --- /dev/null +++ b/packages/core/src/utils/otlp-any-value.ts @@ -0,0 +1,225 @@ +// The OTLP `AnyValue` encoder, shared by the logs, metrics and traces senders. +// +// Every value here comes from application code, so the encoder's job is to +// produce a payload the ingestion service accepts no matter what it is handed. +// A value the server refuses doesn't fail on its own — it 400s the whole +// request, taking every other record in the batch with it. + +import type { OtlpAnyValue, OtlpKeyValue } from '@posthog/types' +import type { Logger } from '../types' +import { isArray, isBoolean, isNull, isNullish, isUndefined } from './type-utils' +import { + CIRCULAR_VALUE, + FUNCTION_VALUE, + MAX_JSON_SAFE_VALUE_DEPTH, + MAX_JSON_SAFE_VALUE_ITEMS, + MAX_JSON_SAFE_VALUE_NODES, + sanitizeString, + TRUNCATED_VALUE, + UNSERIALIZABLE_VALUE, +} from './json-utils' + +// 2^63 — one past int64 max. +const INT64_RANGE_LIMIT = 9223372036854775808 + +// The same bound for the bigint branch. A decimal string rather than a `n` +// literal: this module reaches the browser bundle, which compiles to ES5, and +// a bigint literal there is a syntax error rather than a runtime fallback. +const INT64_RANGE_LIMIT_DECIMAL = '9223372036854775808' + +const propertyIsEnumerable = Object.prototype.propertyIsEnumerable + +interface EncodeState { + /** Containers on the current path, so a back-reference becomes a marker. */ + ancestors: WeakSet + remainingNodes: number +} + +function newState(): EncodeState { + return { ancestors: new WeakSet(), remainingNodes: MAX_JSON_SAFE_VALUE_NODES } +} + +export function toOtlpAnyValue(value: unknown, logger?: Logger): OtlpAnyValue { + try { + return encodeAnyValue(value, logger, newState(), 0) + } catch { + // Runs inside `captureLog`, the metrics flush and span encoding: an error + // escaping here surfaces in the caller's own code. + return { stringValue: UNSERIALIZABLE_VALUE } + } +} + +export function toOtlpKeyValueList(attrs: Record, logger?: Logger): OtlpKeyValue[] { + try { + return encodeKeyValueList(attrs, logger, newState(), 0) + } catch { + return [] + } +} + +function encodeBigInt(value: bigint, logger: Logger | undefined): OtlpAnyValue { + const decimal = value.toString() + const limit = BigInt(INT64_RANGE_LIMIT_DECIMAL) + if (value >= limit || value < -limit) { + logger?.debug(`Attribute ${decimal} is outside the int64 range; encoding it as a string`) + return { stringValue: decimal } + } + return { intValue: decimal } +} + +function encodeAnyValue(value: unknown, logger: Logger | undefined, state: EncodeState, depth: number): OtlpAnyValue { + if (state.remainingNodes <= 0) { + return { stringValue: TRUNCATED_VALUE } + } + state.remainingNodes-- + + if (isBoolean(value)) { + return { boolValue: value } + } + // Reaching this branch proves BigInt exists, so the limit can be built here + // rather than at module load. + if (typeof value === 'bigint') { + return encodeBigInt(value, logger) + } + // typeof, not core's isNumber, which excludes NaN — proto3 JSON distinguishes + // a non-finite float from an ordinary string. + if (typeof value === 'number') { + if (!Number.isFinite(value)) { + return { stringValue: String(value) } + } + if (Number.isInteger(value)) { + if (Number.isSafeInteger(value)) { + return { intValue: String(value) } + } + // Past MAX_SAFE_INTEGER only BigInt gives the double's exact decimal: + // `String(-(2**63))` lands 192 below int64 min, outside the field it is + // about to be parsed into. Without BigInt the value rides as a string, + // which is never range-checked. + if (typeof BigInt === 'undefined') { + return { stringValue: String(value) } + } + const decimal = BigInt(value).toString() + if (value >= INT64_RANGE_LIMIT || value < -INT64_RANGE_LIMIT) { + // An out-of-range intValue 400s the whole logs request; on the metrics + // path it is swallowed server-side and the metric just disappears. + logger?.debug(`Attribute ${decimal} is outside the int64 range; encoding it as a string`) + return { stringValue: decimal } + } + return { intValue: decimal } + } + return { doubleValue: value } + } + if (typeof value === 'string') { + return { stringValue: sanitizeString(value) } + } + // `String(value)` would put a function's source text on the wire. + if (typeof value === 'function') { + return { stringValue: FUNCTION_VALUE } + } + if (typeof value === 'symbol') { + return { stringValue: String(value) } + } + if (typeof value === 'object' && value !== null) { + if (state.ancestors.has(value)) { + return { stringValue: CIRCULAR_VALUE } + } + if (depth >= MAX_JSON_SAFE_VALUE_DEPTH) { + return { stringValue: TRUNCATED_VALUE } + } + if (value instanceof Date) { + const time = value.getTime() + const iso = Number.isFinite(time) ? value.toISOString() : String(value) + // An overridden toISOString can return a non-string, which the server + // refuses for the whole request. + return { stringValue: typeof iso === 'string' ? sanitizeString(iso) : String(iso) } + } + // Registered before the toJSON probe: a toJSON returning a structure that + // references its own object is a cycle like any other. + state.ancestors.add(value) + try { + // The representation a value defines for itself — dayjs, Decimal, an ORM + // document, and a cross-realm Date that fails the `instanceof` above. + try { + const toJSON = (value as { toJSON?: unknown }).toJSON + if (typeof toJSON === 'function') { + return encodeAnyValue(toJSON.call(value), logger, state, depth + 1) + } + } catch { + // A throwing toJSON falls through to the plain walk. + } + if (isArray(value)) { + return { arrayValue: { values: encodeArrayValues(value, logger, state, depth + 1) } } + } + return { + kvlistValue: { + values: encodeKeyValueList(value as Record, logger, state, depth + 1), + }, + } + } finally { + // Siblings that reference the same object are duplication, not a cycle. + state.ancestors.delete(value) + } + } + return { stringValue: sanitizeString(String(value)) } +} + +function encodeArrayValues( + values: unknown[], + logger: Logger | undefined, + state: EncodeState, + depth: number +): OtlpAnyValue[] { + const result: OtlpAnyValue[] = [] + const itemCount = Math.min(values.length, MAX_JSON_SAFE_VALUE_ITEMS) + let index = 0 + for (; index < itemCount && state.remainingNodes > 0; index++) { + try { + const element = index in values ? values[index] : undefined + // Dropped, as iOS and Android do: proto3 JSON has no null AnyValue, and + // both `null` and `{}` here are rejected for the whole request. + if (isNullish(element)) { + continue + } + result.push(encodeAnyValue(element, logger, state, depth)) + } catch { + result.push({ stringValue: UNSERIALIZABLE_VALUE }) + } + } + if (values.length > index) { + result.push({ stringValue: TRUNCATED_VALUE }) + } + return result +} + +function encodeKeyValueList( + attrs: Record, + logger: Logger | undefined, + state: EncodeState, + depth: number +): OtlpKeyValue[] { + const result: OtlpKeyValue[] = [] + for (const key in attrs) { + // for...in walks the prototype chain once own keys are exhausted. Skipped + // rather than broken out of: a proxy can yield keys in any order. + if (!propertyIsEnumerable.call(attrs, key)) { + continue + } + if (result.length >= MAX_JSON_SAFE_VALUE_ITEMS || state.remainingNodes <= 0) { + // Reported rather than written into the attributes: a synthetic key would + // land in the user's own namespace and could collide with a real one. + logger?.debug('Attributes truncated: the value exceeds the OTLP encoder budget') + break + } + try { + const value = attrs[key] + if (isNull(value) || isUndefined(value)) { + continue + } + result.push({ key: sanitizeString(key), value: encodeAnyValue(value, logger, state, depth) }) + } catch { + // A getter that throws costs its own key, not the whole record. + result.push({ key: sanitizeString(key), value: { stringValue: UNSERIALIZABLE_VALUE } }) + } + } + return result +} diff --git a/packages/node/package.json b/packages/node/package.json index c664787e67..240f267fa8 100644 --- a/packages/node/package.json +++ b/packages/node/package.json @@ -46,6 +46,7 @@ "devDependencies": { "@edge-runtime/jest-environment": "^4.0.0", "@posthog-tooling/tsconfig-base": "workspace:*", + "@posthog/types": "workspace:^", "@rslib/core": "catalog:", "@types/express": "^5.0.6", "@types/jest": "catalog:", diff --git a/packages/node/references/posthog-node-references-latest.json b/packages/node/references/posthog-node-references-latest.json index a6abc5887a..d8ba6e53b0 100644 --- a/packages/node/references/posthog-node-references-latest.json +++ b/packages/node/references/posthog-node-references-latest.json @@ -547,6 +547,28 @@ }, "path": "src/entrypoints/index.node.ts" }, + { + "category": "Traces", + "description": "The span currently active on this async execution path, or `null` outside any `withSpan` callback.\nOn the edge build this returns `null` after an `await`, because the active span is tracked synchronously there.\n\nSubject to change in a minor release.", + "details": null, + "id": "getActiveSpan", + "showDocs": true, + "title": "getActiveSpan", + "examples": [ + { + "id": "propagate_the_trace_to_another_service", + "name": "Propagate the trace to another service", + "code": "\n\n// Propagate the trace to another service\nconst traceparent = posthog.getActiveSpan()?.traceparent()\nawait fetch(url, { headers: traceparent ? { traceparent } : {} })\n\n\n\n" + } + ], + "releaseTag": "public", + "params": [], + "returnType": { + "id": "Span | null", + "name": "Span | null" + }, + "path": "src/entrypoints/index.node.ts" + }, { "category": "Feature flags", "description": "Get all feature flag values for a specific user.", @@ -1279,6 +1301,41 @@ }, "path": "src/entrypoints/index.node.ts" }, + { + "category": "Traces", + "description": "Starts a span without making it active — for work that can't wrap a callback. Prefer `withSpan`, which ends the span for you.\nAlways returns a handle, so calling code never has to branch: when the `traces` option is absent, the SDK is disabled, or the user has opted out, the handle is inert and nothing is exported.\n\nSubject to change in a minor release.", + "details": null, + "id": "startSpan", + "showDocs": true, + "title": "startSpan", + "examples": [ + { + "id": "", + "name": "", + "code": "\n\nconst span = posthog.startSpan('checkout', { attributes: { plan: 'pro' } })\nspan.setAttribute('cart.items', 3)\nspan.end()\n\n\n\n" + } + ], + "releaseTag": "public", + "params": [ + { + "description": "", + "isOptional": false, + "type": "string", + "name": "name" + }, + { + "description": "", + "isOptional": true, + "type": "StartSpanOptions", + "name": "options" + } + ], + "returnType": { + "id": "Span", + "name": "Span" + }, + "path": "src/entrypoints/index.node.ts" + }, { "category": "Identification", "description": "Remove properties from a person profile.", @@ -1389,6 +1446,41 @@ }, "path": "src/entrypoints/index.node.ts" }, + { + "category": "Traces", + "description": "Runs a callback with a span active for its duration and ends the span for you — at return for a sync callback, at settle for an async one.\nSpans started inside the callback nest under it automatically. If the callback throws or rejects, the span records the exception and the original error is rethrown unchanged.\nSpans nest across `await` only on the Node runtime, which tracks the active span with `AsyncLocalStorage`. The edge build restores the active span when the callback returns its promise, so spans started after an `await` there begin a new trace.\n\nSubject to change in a minor release.", + "details": null, + "id": "withSpan", + "showDocs": true, + "title": "withSpan", + "examples": [ + { + "id": "", + "name": "", + "code": "\n\nawait posthog.withSpan('POST /checkout', { parent: req.get('traceparent') }, async (span) => {\n span.setAttribute('plan', user.plan)\n return processOrder()\n})\n\n\n\n" + } + ], + "releaseTag": "public", + "params": [ + { + "description": "", + "isOptional": false, + "type": "string", + "name": "name" + }, + { + "description": "", + "isOptional": false, + "type": "(span: Span) => T", + "name": "fn" + } + ], + "returnType": { + "id": "T", + "name": "T" + }, + "path": "src/entrypoints/index.node.ts" + }, { "category": "", "details": null, @@ -3492,6 +3584,11 @@ "type": "MetricsConfig", "name": "metrics" }, + { + "description": "Configuration for distributed tracing (`startSpan` / `withSpan`). Tracing is\noff until this is set; supplying it is all that's needed to turn it on.\n\nSet `serviceName` so spans can be attributed and grouped per service — the\nproduct aggregates operations by service and span name.\n\n`shutdown()` drains spans that have already ended, within the shutdown\ntimeout; spans still open at that point are discarded.", + "type": "TracesConfig", + "name": "traces" + }, { "description": "Credential that enables local feature flag evaluation and remote config.\n\nAccepts either a Personal API Key (`phx_...`) or a Project Secret API Key (`phs_...`).\nWhen provided, the client can evaluate feature flags locally and decrypt remote\nconfig payloads via `getRemoteConfigPayload`. Prefer this over the deprecated\n`personalApiKey` option; when both are set, `secretKey` takes precedence.", "type": "string", @@ -3973,6 +4070,13 @@ "path": "../core/src/metrics/types.ts", "example": "{\n kind: 'ok';\n} | {\n kind: 'retry-later';\n error: unknown;\n} | {\n kind: 'too-large';\n} | {\n kind: 'fatal';\n error: unknown;\n}" }, + { + "id": "SendTracesBatchOutcome", + "name": "SendTracesBatchOutcome", + "properties": [], + "path": "../core/src/traces/types.ts", + "example": "{\n kind: 'ok';\n} | {\n kind: 'retry-later';\n error: unknown;\n} | {\n kind: 'too-large';\n} | {\n kind: 'fatal';\n error: unknown;\n}" + }, { "id": "SentryIntegrationOptions", "name": "SentryIntegrationOptions", @@ -4026,6 +4130,12 @@ "path": "../core/src/error-tracking/types.ts", "example": "(typeof severityLevels)[number]" }, + { + "id": "SpanContextManager", + "name": "SpanContextManager", + "properties": [], + "path": "../core/src/traces/types.ts" + }, { "id": "SpecificQuestionBranching", "name": "SpecificQuestionBranching", @@ -4609,6 +4719,7 @@ "Error tracking", "Privacy", "Feature flags", + "Traces", "Context" ] } \ No newline at end of file diff --git a/packages/node/src/__tests__/traces-defaults.spec.ts b/packages/node/src/__tests__/traces-defaults.spec.ts new file mode 100644 index 0000000000..0e2f7b8ad3 --- /dev/null +++ b/packages/node/src/__tests__/traces-defaults.spec.ts @@ -0,0 +1,66 @@ +import { resolveTracesConfig } from '../traces-defaults' + +describe('resolveTracesConfig', () => { + it('applies the documented defaults', () => { + expect(resolveTracesConfig(undefined)).toMatchObject({ + flushIntervalMs: 5000, + maxExportBatchSize: 512, + maxQueueSize: 2048, + }) + }) + + it('leaves serviceName unset so core supplies unknown_service', () => { + expect(resolveTracesConfig({}).serviceName).toBeUndefined() + }) + + it('honours explicit values', () => { + expect( + resolveTracesConfig({ serviceName: 'checkout', flushIntervalMs: 1000, maxExportBatchSize: 50 }) + ).toMatchObject({ + serviceName: 'checkout', + flushIntervalMs: 1000, + maxExportBatchSize: 50, + }) + }) + + it('lets OTLP resource attributes override the named fields', () => { + const resolved = resolveTracesConfig({ + serviceName: 'named', + serviceVersion: '1.0.0', + environment: 'staging', + resourceAttributes: { + 'service.name': 'from-attributes', + 'service.version': '2.0.0', + 'deployment.environment': 'production', + }, + }) + + expect(resolved.serviceName).toBe('from-attributes') + expect(resolved.serviceVersion).toBe('2.0.0') + expect(resolved.environment).toBe('production') + }) + + it.each([0, -1, 0.5, Number.NaN, Number.POSITIVE_INFINITY])( + 'falls back to the default for an unusable maxExportBatchSize (%p)', + (value) => { + // A non-positive batch size reaches an export loop that cannot make + // progress with it, so it spins forever posting empty batches. + expect(resolveTracesConfig({ maxExportBatchSize: value }).maxExportBatchSize).toBe(512) + } + ) + + it('floors a fractional batch size to an integer', () => { + expect(resolveTracesConfig({ maxExportBatchSize: 10.9 }).maxExportBatchSize).toBe(10) + }) + + it.each([0, -1, Number.NaN])('falls back to the default for an unusable flushIntervalMs (%p)', (value) => { + expect(resolveTracesConfig({ flushIntervalMs: value }).flushIntervalMs).toBe(5000) + }) + + it('keeps the queue at least as large as the export batch', () => { + // A queue smaller than the flush trigger would stop the depth-based flush + // from ever firing. + expect(resolveTracesConfig({ maxExportBatchSize: 5000 }).maxQueueSize).toBe(5000) + expect(resolveTracesConfig({ maxExportBatchSize: 10 }).maxQueueSize).toBe(2048) + }) +}) diff --git a/packages/node/src/__tests__/traces.spec.ts b/packages/node/src/__tests__/traces.spec.ts new file mode 100644 index 0000000000..0180cde7d7 --- /dev/null +++ b/packages/node/src/__tests__/traces.spec.ts @@ -0,0 +1,322 @@ +import { PostHog } from '@/entrypoints/index.node' +import type { OtlpSpan, OtlpTracesPayload } from '@posthog/types' +import { waitForPromises } from './utils' + +jest.mock('../version', () => ({ version: '1.2.3' })) + +const mockedFetch = jest.spyOn(globalThis, 'fetch').mockImplementation() + +describe('PostHog traces', () => { + let posthog: PostHog + + const createClient = (options: Record = {}): PostHog => + new PostHog('phc_test_key', { + host: 'http://example.com', + flushAt: 1, + fetchRetryCount: 0, + disableCompression: true, + traces: { serviceName: 'checkout-api' }, + ...options, + }) + + const traceRequests = (): [string, any][] => + mockedFetch.mock.calls.filter((call) => (call[0] as string).includes('/i/v1/traces')) as [string, any][] + + const sentPayloads = (): OtlpTracesPayload[] => + traceRequests().map(([, init]) => JSON.parse(init.body as string) as OtlpTracesPayload) + + const sentSpans = (): OtlpSpan[] => sentPayloads().flatMap((p) => p.resourceSpans[0].scopeSpans[0].spans) + + const attributeOf = (span: OtlpSpan, key: string): any => span.attributes?.find((a) => a.key === key)?.value + + // Traces run their own flush cycle, separate from the analytics-events + // pipeline — `posthog.flush()` does not drain them today. + const DEFAULT_TRACES_FLUSH_INTERVAL_MS = 5000 + const flushTraces = async (): Promise => { + await jest.advanceTimersByTimeAsync(DEFAULT_TRACES_FLUSH_INTERVAL_MS) + await waitForPromises() + } + + beforeEach(() => { + jest.clearAllMocks() + mockedFetch.mockResolvedValue({ + status: 200, + text: () => Promise.resolve('{}'), + json: () => Promise.resolve({}), + } as any) + posthog = createClient() + }) + + afterEach(async () => { + await posthog.shutdown() + }) + + describe('configuration', () => { + it('is off until the traces option is supplied', async () => { + const untraced = createClient({ traces: undefined }) + const span = untraced.startSpan('checkout') + span.end() + await untraced.shutdown() + + expect(span.traceparent()).toBeNull() + expect(traceRequests()).toHaveLength(0) + }) + + it('still runs a withSpan callback when tracing is off', async () => { + const untraced = createClient({ traces: undefined }) + const fn = jest.fn(() => 'value') + + expect(untraced.withSpan('job', fn)).toBe('value') + expect(fn).toHaveBeenCalledTimes(1) + expect(untraced.getActiveSpan()).toBeNull() + await untraced.shutdown() + }) + }) + + describe('transport', () => { + it('posts to /i/v1/traces with bearer auth', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + const [url, init] = traceRequests()[0] + expect(url).toBe('http://example.com/i/v1/traces') + expect(init.method).toBe('POST') + expect(init.headers.Authorization).toBe('Bearer phc_test_key') + expect(init.headers['Content-Type']).toBe('application/json') + }) + + it('does not put the project key in the query string', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + expect(traceRequests()[0][0]).not.toContain('token=') + }) + + it('sends the service name as a resource attribute', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + // The server reads service_name only from this attribute; without it the + // spans are stored with an empty service and are unattributable. + expect(sentPayloads()[0].resourceSpans[0].resource.attributes).toContainEqual({ + key: 'service.name', + value: { stringValue: 'checkout-api' }, + }) + }) + + it('identifies the SDK in the scope and resource', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + const [resourceSpan] = sentPayloads()[0].resourceSpans + expect(resourceSpan.scopeSpans[0].scope).toEqual({ name: 'posthog-node', version: '1.2.3' }) + expect(resourceSpan.resource.attributes).toContainEqual({ + key: 'telemetry.sdk.name', + value: { stringValue: 'posthog-node' }, + }) + }) + }) + + describe('span shape', () => { + it('exports well-formed W3C identifiers', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + const [span] = sentSpans() + expect(span.traceId).toMatch(/^[0-9a-f]{32}$/) + expect(span.spanId).toMatch(/^[0-9a-f]{16}$/) + }) + + it('encodes timestamps as nanosecond strings', async () => { + posthog.startSpan('checkout').end() + await flushTraces() + + const [span] = sentSpans() + expect(typeof span.startTimeUnixNano).toBe('string') + expect(Number(span.endTimeUnixNano)).toBeGreaterThanOrEqual(Number(span.startTimeUnixNano)) + }) + + it('encodes integer attributes as stringified int64', async () => { + posthog.startSpan('checkout', { attributes: { 'http.status_code': 200 } }).end() + await flushTraces() + + expect(attributeOf(sentSpans()[0], 'http.status_code')).toEqual({ intValue: '200' }) + }) + + it('replaces an empty span name rather than poisoning the batch', async () => { + // A malformed span 400s the entire request, and 400 is non-retriable — + // one bad name would silently destroy every other span in the batch. + posthog.startSpan('').end() + await flushTraces() + + expect(sentSpans()[0].name).toBe('unknown') + }) + }) + + describe('active span context', () => { + it('nests spans started inside a withSpan callback', async () => { + posthog.withSpan('outer', () => { + posthog.withSpan('inner', () => undefined) + }) + await flushTraces() + + const inner = sentSpans().find((s) => s.name === 'inner')! + const outer = sentSpans().find((s) => s.name === 'outer')! + expect(inner.traceId).toBe(outer.traceId) + expect(inner.parentSpanId).toBe(outer.spanId) + }) + + it('keeps the span active across an await', async () => { + // This is what AsyncLocalStorage buys over the synchronous fallback: a + // span started after an await still nests correctly. + await posthog.withSpan('outer', async () => { + await Promise.resolve() + posthog.withSpan('inner', () => undefined) + }) + await flushTraces() + + const inner = sentSpans().find((s) => s.name === 'inner')! + const outer = sentSpans().find((s) => s.name === 'outer')! + expect(inner.parentSpanId).toBe(outer.spanId) + }) + + it('isolates concurrent requests from each other', async () => { + await Promise.all([ + posthog.withSpan('request-a', async () => { + await Promise.resolve() + posthog.withSpan('child-a', () => undefined) + }), + posthog.withSpan('request-b', async () => { + await Promise.resolve() + posthog.withSpan('child-b', () => undefined) + }), + ]) + await flushTraces() + + const byName = (name: string): OtlpSpan => sentSpans().find((s) => s.name === name)! + expect(byName('child-a').parentSpanId).toBe(byName('request-a').spanId) + expect(byName('child-b').parentSpanId).toBe(byName('request-b').spanId) + expect(byName('request-a').traceId).not.toBe(byName('request-b').traceId) + }) + + it('reads null outside any callback', () => { + expect(posthog.getActiveSpan()).toBeNull() + }) + }) + + describe('auto-context from the request context', () => { + it('attaches the request distinct id and session id', async () => { + // Fed by the Express/NestJS middleware from the X-POSTHOG-DISTINCT-ID and + // X-POSTHOG-SESSION-ID tracing headers. + posthog.withContext({ distinctId: 'user-123', sessionId: 'session-123' }, () => { + posthog.startSpan('checkout').end() + }) + await flushTraces() + + const [span] = sentSpans() + expect(attributeOf(span, 'posthogDistinctId')).toEqual({ stringValue: 'user-123' }) + expect(attributeOf(span, 'sessionId')).toEqual({ stringValue: 'session-123' }) + }) + + it('omits the keys outside a request context', async () => { + posthog.startSpan('background-job').end() + await flushTraces() + + expect(attributeOf(sentSpans()[0], 'posthogDistinctId')).toBeUndefined() + expect(attributeOf(sentSpans()[0], 'sessionId')).toBeUndefined() + }) + }) + + describe('distributed tracing', () => { + it('continues a trace from an inbound traceparent header', async () => { + const traceId = '4bf92f3577b34da6a3ce929d0e0e4736' + const spanId = '00f067aa0ba902b7' + + posthog.withSpan('POST /checkout', { parent: `00-${traceId}-${spanId}-01` }, () => undefined) + await flushTraces() + + const [span] = sentSpans() + expect(span.traceId).toBe(traceId) + expect(span.parentSpanId).toBe(spanId) + }) + + it('produces a traceparent for the next service', async () => { + let traceparent: string | null = null + posthog.withSpan('POST /checkout', () => { + traceparent = posthog.getActiveSpan()!.traceparent() + }) + await flushTraces() + + const [span] = sentSpans() + expect(traceparent).toBe(`00-${span.traceId}-${span.spanId}-01`) + }) + }) + + describe('errors', () => { + it('records a thrown error and rethrows it unchanged', async () => { + const thrown = new TypeError('boom') + expect(() => + posthog.withSpan('job', () => { + throw thrown + }) + ).toThrow(thrown) + + await flushTraces() + + const [span] = sentSpans() + expect(span.status).toEqual({ code: 2, message: 'boom' }) + expect(span.events?.[0].name).toBe('exception') + }) + }) + + describe('413 handling', () => { + it('halves the batch on a real 413 rather than retrying it forever', async () => { + // `_sendTracesBatch` classifies the response itself; the core halving + // logic is dead unless that mapping is right, and every core test mocks + // the outcome rather than the status. + let requests = 0 + mockedFetch.mockImplementation(((url: string) => { + if (!url.includes('/i/v1/traces')) { + return Promise.resolve({ status: 200, text: () => Promise.resolve('ok') } as any) + } + requests++ + return Promise.resolve({ + status: requests === 1 ? 413 : 200, + text: () => Promise.resolve(requests === 1 ? 'too large' : '{}'), + } as any) + }) as any) + + const client = createClient({ traces: { serviceName: 'checkout-api', maxExportBatchSize: 2 } }) + client.startSpan('a').end() + client.startSpan('b').end() + await client.shutdown() + + const batchSizes = sentPayloads().map((p) => p.resourceSpans[0].scopeSpans[0].spans.length) + expect(batchSizes).toEqual([2, 1, 1]) + }) + }) + + describe('flush cycle', () => { + it('flushes on its own interval, not with the events pipeline', async () => { + // Traces are a separate pipeline with their own queue and endpoint. + // `posthog.flush()` drains events only; wiring traces into it is a + // deliberate follow-up because it changes that method's contract. + posthog.startSpan('checkout').end() + await posthog.flush() + expect(traceRequests()).toHaveLength(0) + + await flushTraces() + expect(sentSpans()).toHaveLength(1) + }) + }) + + describe('shutdown', () => { + it('drains queued spans', async () => { + posthog.startSpan('a').end() + posthog.startSpan('b').end() + await posthog.shutdown() + + expect(sentSpans()).toHaveLength(2) + }) + }) +}) diff --git a/packages/node/src/client.ts b/packages/node/src/client.ts index d7c499fb10..190ba4a7d9 100644 --- a/packages/node/src/client.ts +++ b/packages/node/src/client.ts @@ -17,14 +17,18 @@ import { PostHogFlagsResponse, PostHogMetrics, PostHogPersistedProperty, + PostHogTraces, + NOOP_SPAN, Properties, resolveMetricsConfig, RetriableOptions, raceWithTimeout, safeSetTimeout, + SyncSpanContextManager, uuidv7, } from '@posthog/core' -import type { Metrics } from '@posthog/core' +import type { Metrics, Span, SpanContextManager, StartSpanOptions, TraceSdkContext } from '@posthog/core' +import { resolveTracesConfig } from './traces-defaults' import { AllFlagsOptions, EventMessage, @@ -144,6 +148,7 @@ export abstract class PostHogBackendClient extends PostHogCoreStateless implemen public readonly options: PostHogOptions protected readonly context?: IPostHogContext private _metrics?: PostHogMetrics + private _traces?: PostHogTraces private readonly captureMode: CaptureMode private _v1Sender?: V1CaptureSender @@ -600,6 +605,133 @@ export abstract class PostHogBackendClient extends PostHogCoreStateless implemen return this._metrics } + /** + * Active-span tracking. Overridden by the Node entrypoint with an + * `AsyncLocalStorage`-backed manager; the edge build keeps this synchronous + * fallback, matching how `initializeContext` already differs between them. + */ + protected initializeSpanContextManager(): SpanContextManager { + return new SyncSpanContextManager() + } + + /** + * The traces pipeline, built on first use. Returns `undefined` when the + * `traces` client option is absent — tracing is off until configured. + */ + private get _tracesPipeline(): PostHogTraces | undefined { + if (!this.options.traces) { + return undefined + } + if (!this._traces) { + this._traces = new PostHogTraces( + this, + resolveTracesConfig(this.options.traces), + this._logger, + () => this._tracingContext(), + this.initializeSpanContextManager() + ) + } + return this._traces + } + + /** + * PostHog context attached to every span, so traces join back to persons and + * sessions. + * + * A server process has no ambient identity, so these come from the current + * request context — populated by the Express/NestJS middleware from the + * `X-POSTHOG-DISTINCT-ID` / `X-POSTHOG-SESSION-ID` tracing headers, or set + * directly via `withContext`. Outside a request the keys are simply omitted. + */ + private _tracingContext(): TraceSdkContext { + const context = this.context?.get() + return { distinctId: context?.distinctId, sessionId: context?.sessionId } + } + + /** + * Starts a span without making it active — for work that can't wrap a + * callback. Prefer `withSpan`, which ends the span for you. + * + * Always returns a handle, so calling code never has to branch: when the + * `traces` option is absent, the SDK is disabled, or the user has opted out, + * the handle is inert and nothing is exported. + * + * {@label Traces} + * + * @experimental Subject to change in a minor release. + * + * @example + * ```ts + * const span = posthog.startSpan('checkout', { attributes: { plan: 'pro' } }) + * span.setAttribute('cart.items', 3) + * span.end() + * ``` + */ + startSpan(name: string, options?: StartSpanOptions): Span { + return this._tracesPipeline?.startSpan(name, options) ?? NOOP_SPAN + } + + /** + * Runs a callback with a span active for its duration and ends the span for + * you — at return for a sync callback, at settle for an async one. + * + * Spans started inside the callback nest under it automatically. If the + * callback throws or rejects, the span records the exception and the original + * error is rethrown unchanged. + * + * Spans nest across `await` only on the Node runtime, which tracks the active + * span with `AsyncLocalStorage`. The edge build restores the active span when + * the callback returns its promise, so spans started after an `await` there + * begin a new trace. + * + * {@label Traces} + * + * @experimental Subject to change in a minor release. + * + * @example + * ```ts + * await posthog.withSpan('POST /checkout', { parent: req.get('traceparent') }, async (span) => { + * span.setAttribute('plan', user.plan) + * return processOrder() + * }) + * ``` + */ + withSpan(name: string, fn: (span: Span) => T): T + withSpan(name: string, options: StartSpanOptions, fn: (span: Span) => T): T + withSpan(name: string, optionsOrFn: StartSpanOptions | ((span: Span) => T), maybeFn?: (span: Span) => T): T { + const options = typeof optionsOrFn === 'function' ? undefined : optionsOrFn + const fn = (typeof optionsOrFn === 'function' ? optionsOrFn : maybeFn) as (span: Span) => T + + const pipeline = this._tracesPipeline + if (!pipeline) { + // Tracing off: still run the callback exactly once, with an inert handle. + return fn(NOOP_SPAN) + } + return options ? pipeline.withSpan(name, options, fn) : pipeline.withSpan(name, fn) + } + + /** + * The span currently active on this async execution path, or `null` outside + * any `withSpan` callback. + * + * On the edge build this returns `null` after an `await`, because the active + * span is tracked synchronously there. + * + * {@label Traces} + * + * @experimental Subject to change in a minor release. + * + * @example + * ```ts + * // Propagate the trace to another service + * const traceparent = posthog.getActiveSpan()?.traceparent() + * await fetch(url, { headers: traceparent ? { traceparent } : {} }) + * ``` + */ + getActiveSpan(): Span | null { + return this._tracesPipeline?.getActiveSpan() ?? null + } + /** * Get the custom user agent string for this client. * @@ -2604,6 +2736,17 @@ export abstract class PostHogBackendClient extends PostHogCoreStateless implemen // merged back onto a re-armed timer after teardown. this._metrics.reset() } + if (this._traces) { + // Same treatment as metrics: send what's queued, raced against the shared + // shutdown budget so an unresponsive transport can't hold shutdown past + // the caller's deadline, then reset so a flush that lost the race can't + // re-arm a timer after teardown. + await raceWithTimeout( + this._traces.flush().catch(() => {}), + Math.max(0, shutdownDeadlineMs - Date.now()) + ) + this._traces.reset() + } try { return await super._shutdown(Math.max(0, shutdownDeadlineMs - Date.now())) } finally { diff --git a/packages/node/src/entrypoints/index.node.ts b/packages/node/src/entrypoints/index.node.ts index 1c872b4ed2..96a9fed515 100644 --- a/packages/node/src/entrypoints/index.node.ts +++ b/packages/node/src/entrypoints/index.node.ts @@ -7,7 +7,9 @@ import { createRelativePathModifier } from '../extensions/error-tracking/modifie import type { PostHogFetchBodyBytes } from '@posthog/core' import { PostHogBackendClient } from '../client' import { ErrorTracking as CoreErrorTracking } from '@posthog/core' +import type { SpanContextManager } from '@posthog/core' import { PostHogContext } from '../extensions/context/context' +import { AsyncLocalStorageSpanContextManager } from '../extensions/context/span-context.node' import { gzipCompress } from '../gzip.node' export class PostHog extends PostHogBackendClient { @@ -23,6 +25,10 @@ export class PostHog extends PostHogBackendClient { return new PostHogContext() } + protected override initializeSpanContextManager(): SpanContextManager { + return new AsyncLocalStorageSpanContextManager() + } + protected override createErrorPropertiesBuilder(): CoreErrorTracking.ErrorPropertiesBuilder { return new CoreErrorTracking.ErrorPropertiesBuilder( [ diff --git a/packages/node/src/exports.ts b/packages/node/src/exports.ts index a47ed77e8f..23e4897a93 100644 --- a/packages/node/src/exports.ts +++ b/packages/node/src/exports.ts @@ -14,6 +14,19 @@ export type { FeatureFlagErrorType } from '@posthog/core' // and API surface without a direct @posthog/core dependency. export type { CaptureMetricOptions, Metrics, MetricsConfig } from '@posthog/core' +// Tracing types re-exported so consumers can name the `traces` client option and +// the span API without a direct @posthog/core dependency. +export type { + Span, + SpanAttributes, + SpanAttributeValue, + SpanKind, + SpanStatusCode, + SpanTimeInput, + StartSpanOptions, + TracesConfig, +} from '@posthog/core' + // Identity helpers re-exported from core for posthog-node consumers managing // distinct_id outside the browser SDK (e.g. Lambda functions handing out // `download-app` redirects). Closes #2143. diff --git a/packages/node/src/extensions/context/span-context.node.ts b/packages/node/src/extensions/context/span-context.node.ts new file mode 100644 index 0000000000..733232a558 --- /dev/null +++ b/packages/node/src/extensions/context/span-context.node.ts @@ -0,0 +1,23 @@ +import { AsyncLocalStorage } from 'node:async_hooks' +import type { Span, SpanContextManager } from '@posthog/core' + +/** + * Active-span tracking backed by `AsyncLocalStorage`, so a span stays active + * across `await` boundaries and through any async work its callback starts. + * + * Lives here rather than in core because core ships to browsers, edge runtimes + * and React Native and must not import `node:async_hooks`. The edge entrypoint + * falls back to core's synchronous manager, matching how `initializeContext` + * already differs between the two builds. + */ +export class AsyncLocalStorageSpanContextManager implements SpanContextManager { + private readonly _storage = new AsyncLocalStorage() + + active(): Span | undefined { + return this._storage.getStore() + } + + with(span: Span, fn: () => T): T { + return this._storage.run(span, fn) + } +} diff --git a/packages/node/src/traces-defaults.ts b/packages/node/src/traces-defaults.ts new file mode 100644 index 0000000000..ee8b9074bf --- /dev/null +++ b/packages/node/src/traces-defaults.ts @@ -0,0 +1,38 @@ +import type { ResolvedTracesConfig, TracesConfig } from '@posthog/core' + +// OpenTelemetry's BatchSpanProcessor defaults, which the tracing ecosystem has +// converged on and which sit comfortably under the server's 2 MB body cap: +// a full 512-span batch of typical server spans gzips to well under it. +const DEFAULT_FLUSH_INTERVAL_MS = 5000 +const DEFAULT_MAX_EXPORT_BATCH_SIZE = 512 +const DEFAULT_MAX_QUEUE_SIZE = 2048 + +/** + * Coerces a caller-supplied positive-integer option, falling back to the default + * for anything unusable. `0`, a negative, or `NaN` reaching the export loop + * would make it unable to make progress. + */ +function positiveInteger(value: number | undefined, fallback: number): number { + return typeof value === 'number' && Number.isFinite(value) && value >= 1 ? Math.floor(value) : fallback +} + +/** + * Resolves the public `traces` config into the shape core `PostHogTraces` consumes. + * + * OTLP resource attributes take precedence over the named fields, matching how + * the logs config resolves — a user who sets `service.name` directly means it. + */ +export function resolveTracesConfig(config: TracesConfig | undefined): ResolvedTracesConfig { + const resourceAttributes = config?.resourceAttributes + const maxExportBatchSize = positiveInteger(config?.maxExportBatchSize, DEFAULT_MAX_EXPORT_BATCH_SIZE) + return { + serviceName: (resourceAttributes?.['service.name'] as string | undefined) ?? config?.serviceName, + serviceVersion: (resourceAttributes?.['service.version'] as string | undefined) ?? config?.serviceVersion, + environment: (resourceAttributes?.['deployment.environment'] as string | undefined) ?? config?.environment, + resourceAttributes, + flushIntervalMs: positiveInteger(config?.flushIntervalMs, DEFAULT_FLUSH_INTERVAL_MS), + maxExportBatchSize, + // Never below the flush trigger, or the depth-based flush could never fire. + maxQueueSize: Math.max(DEFAULT_MAX_QUEUE_SIZE, maxExportBatchSize), + } +} diff --git a/packages/node/src/types.ts b/packages/node/src/types.ts index 9032a43696..2103dea5d6 100644 --- a/packages/node/src/types.ts +++ b/packages/node/src/types.ts @@ -9,6 +9,9 @@ import type { PostHogFetchResponse, PostHogFlagsAndPayloadsResponse, Properties, + Span, + StartSpanOptions, + TracesConfig, } from '@posthog/core' import { ContextData, ContextOptions } from './extensions/context/types' @@ -180,6 +183,25 @@ export type PostHogOptions = Omit stripe.charge(order)) + * ``` + * + * @experimental Subject to change in a minor release. + */ + traces?: TracesConfig /** * Credential that enables local feature flag evaluation and remote config. * @@ -796,6 +818,30 @@ export interface IPostHog { */ readonly metrics: Metrics + /** + * @description Starts a span without making it active, for work that can't wrap a callback. + * Prefer `withSpan`. Always returns a handle — an inert one when tracing is off — so calling + * code never has to branch. + * @experimental Subject to change in a minor release. + */ + startSpan(name: string, options?: StartSpanOptions): Span + + /** + * @description Runs a callback with a span active for its duration and ends the span at return + * (sync) or settle (async). Spans started inside nest automatically; a throw or rejection is + * recorded on the span and rethrown unchanged. + * @experimental Subject to change in a minor release. + */ + withSpan(name: string, fn: (span: Span) => T): T + withSpan(name: string, options: StartSpanOptions, fn: (span: Span) => T): T + + /** + * @description The span currently active on this async execution path, or null outside any + * `withSpan` callback. + * @experimental Subject to change in a minor release. + */ + getActiveSpan(): Span | null + /** * @description Flushes the events still in the queue and clears the feature flags poller to allow for * a clean shutdown. diff --git a/packages/react-native/references/posthog-react-native-references-latest.json b/packages/react-native/references/posthog-react-native-references-latest.json index fcb86511b2..f9f1fe7398 100644 --- a/packages/react-native/references/posthog-react-native-references-latest.json +++ b/packages/react-native/references/posthog-react-native-references-latest.json @@ -4433,6 +4433,13 @@ "path": "../core/src/metrics/types.ts", "example": "{\n kind: 'ok';\n} | {\n kind: 'retry-later';\n error: unknown;\n} | {\n kind: 'too-large';\n} | {\n kind: 'fatal';\n error: unknown;\n}" }, + { + "id": "SendTracesBatchOutcome", + "name": "SendTracesBatchOutcome", + "properties": [], + "path": "../core/src/traces/types.ts", + "example": "{\n kind: 'ok';\n} | {\n kind: 'retry-later';\n error: unknown;\n} | {\n kind: 'too-large';\n} | {\n kind: 'fatal';\n error: unknown;\n}" + }, { "id": "SeverityLevel", "name": "SeverityLevel", diff --git a/packages/types/src/index.ts b/packages/types/src/index.ts index d1a399c486..3e4add1c7f 100644 --- a/packages/types/src/index.ts +++ b/packages/types/src/index.ts @@ -128,3 +128,21 @@ export type { OtlpMetricsPayload, } from './capture-metric' export { OTLP_AGGREGATION_TEMPORALITY_DELTA } from './capture-metric' + +// Distributed tracing types +export type { + SpanKind, + SpanStatusCode, + SpanAttributeValue, + SpanAttributes, + SpanTimeInput, + StartSpanOptions, + Span, + TracesConfig, + OtlpSpanAnyValue, + OtlpSpanKeyValue, + OtlpSpanEvent, + OtlpSpanStatus, + OtlpSpan, + OtlpTracesPayload, +} from './traces' diff --git a/packages/types/src/traces.ts b/packages/types/src/traces.ts new file mode 100644 index 0000000000..e6c8a84111 --- /dev/null +++ b/packages/types/src/traces.ts @@ -0,0 +1,277 @@ +import type { OtlpAnyValue, OtlpKeyValue } from './capture-log' + +/** + * Types for the distributed tracing API (`startSpan` / `withSpan` / `getActiveSpan`). + * + * Spans are exported as OpenTelemetry-shaped OTLP records to PostHog's tracing + * endpoint. PostHog does not depend on the OpenTelemetry SDK — these types are the + * SDK-facing surface, and the OTLP integer enums stay a wire-level concern. + */ + +/** + * What kind of work a span represents. Mirrors the OpenTelemetry span kinds. + * + * @default 'internal' + * + * @experimental Subject to change in a minor release. + */ +export type SpanKind = 'internal' | 'server' | 'client' | 'producer' | 'consumer' + +/** + * Outcome of the operation a span covers. A span that never has a status set is + * exported as `unset`, which is not the same as `ok`. + * + * @experimental Subject to change in a minor release. + */ +export type SpanStatusCode = 'ok' | 'error' + +/** + * A value that can be attached to a span, span event, or resource. + * + * The ingestion service flattens attribute values to strings for storage, so + * primitives are strongly preferred — nested arrays and objects survive only as + * serialized strings and cannot be filtered on. `null` and `undefined` drop the key. + * + * @experimental Subject to change in a minor release. + */ +export type SpanAttributeValue = + | string + | number + | boolean + | bigint + | SpanAttributeValue[] + | { [key: string]: SpanAttributeValue } + | null + | undefined + +export type SpanAttributes = Record + +/** + * A point in time, as a millisecond epoch number or a `Date`. + * + * @experimental Subject to change in a minor release. + */ +export type SpanTimeInput = number | Date + +/** + * Options accepted by `startSpan` and `withSpan`. + * + * @experimental Subject to change in a minor release. + */ +export interface StartSpanOptions { + /** + * What kind of work the span represents. + * + * @default 'internal' + */ + kind?: SpanKind + + /** + * Attributes to set at span start. User-supplied keys win over the + * SDK's auto-attached context attributes. + */ + attributes?: SpanAttributes + + /** + * Parent of this span: either a span handle, or a raw W3C `traceparent` + * string to continue a trace started by another service. + * + * When omitted the parent is the currently active span, or none. Only + * handles returned by this SDK are honoured; any other `Span` yields an + * inert span. + * + * @example Continue an inbound trace + * ```ts + * posthog.withSpan('POST /checkout', { parent: req.get('traceparent') }, handler) + * ``` + */ + parent?: Span | string + + /** + * The W3C `tracestate` value accompanying a `traceparent`-string `parent`. + * Ignored when `parent` is a span handle — those inherit the parent's + * tracestate. Preserved opaquely and passed on to children. + */ + tracestate?: string + + /** + * Backdate the span's start. Values outside the representable range fall + * back to the current time; starts more than 24 hours old are warned about, + * because the server clamps them to receive time. + */ + startTime?: SpanTimeInput +} + +/** + * A handle to a span in progress. + * + * Every method is safe to call at any time, including after `end()` and on + * no-op handles, so calling code never has to branch on whether tracing is on. + * + * @experimental Subject to change in a minor release. + */ +export interface Span { + /** Set a single attribute. Ignored after `end()`. */ + setAttribute(key: string, value: SpanAttributeValue): this + + /** Merge several attributes at once. Ignored after `end()`. */ + setAttributes(attributes: SpanAttributes): this + + /** + * Record a timestamped event within the span, e.g. a cache miss or a retry. + * Defaults to the current time. + */ + addEvent(name: string, attributes?: SpanAttributes, timestamp?: SpanTimeInput): this + + /** + * Set the span's outcome. Last write wins. + * + * When a `withSpan` callback throws, the SDK sets `error` automatically — + * unless the callback already set `ok`, which is treated as final. + */ + setStatus(status: SpanStatusCode, message?: string): this + + /** + * Record an exception on the span: sets status `error` and attaches an + * `exception` event carrying `exception.type` and `exception.message`. + * Does not end the span. + */ + recordException(error: unknown): this + + /** + * Replace the span's name. Useful when the low-cardinality name is only + * known after work begins — a route template resolving mid-request, say. + * + * Span names should be low-cardinality operation names (`GET /users/:id`), + * never interpolated with ids: PostHog aggregates operations by service and + * name, so variable values belong in attributes. + */ + updateName(name: string): this + + /** + * This span's W3C `traceparent` header value (`00---01`), + * for propagating the trace to another service. Returns `null` on a no-op + * span, so an id that was never recorded cannot propagate. + */ + traceparent(): string | null + + /** This span's W3C `tracestate` value, or `null` when it has none. */ + tracestate(): string | null + + /** + * End the span and queue it for export. Idempotent — later calls no-op. + * + * @param endTime - Override the recorded end. Invalid values fall back to + * the derived end time; an end before the start is corrected to the start. + */ + end(endTime?: SpanTimeInput): void +} + +/** + * Configuration for distributed tracing, passed as the `traces` client option. + * Tracing stays off until this object is supplied. + * + * @example + * ```ts + * const posthog = new PostHog('phc_...', { traces: { serviceName: 'checkout-api' } }) + * ``` + * + * @experimental Subject to change in a minor release. + */ +export interface TracesConfig { + /** + * Name of the service producing these spans, attached as the OTLP + * `service.name` resource attribute. PostHog groups operations by service + * and span name, so this is what makes spans attributable. + * + * @default 'unknown_service' + */ + serviceName?: string + + /** Service version, attached as OTLP `service.version`. */ + serviceVersion?: string + + /** + * Deployment environment (e.g. `'production'`, `'staging'`), attached as + * OTLP `deployment.environment`. + */ + environment?: string + + /** + * Extra OTLP resource attributes attached to every batch. Applied first; + * SDK-controlled identity keys (`service.*`, `telemetry.sdk.*`) are layered + * on top so they cannot be clobbered. Use `serviceName` / `serviceVersion` / + * `environment` to set those. + */ + resourceAttributes?: SpanAttributes + + /** + * How often queued spans are flushed, in milliseconds. Spans also flush when + * the queue reaches `maxExportBatchSize` and on `shutdown()`. + * + * @default 5000 + */ + flushIntervalMs?: number + + /** + * Maximum spans per outbound request, and the queue depth that triggers an + * immediate flush. On a 413 the SDK halves this, retries the same spans, then + * ramps back up. + * + * @default 512 + */ + maxExportBatchSize?: number +} + +// ============================================================================ +// OTLP wire types +// +// `AnyValue` and `KeyValue` are the same shapes the logs and metrics payloads +// use, and one shared encoder produces all three, so spans alias them rather +// than redeclaring them. The alias names remain so the span types below read as +// span types. +// ============================================================================ + +export type OtlpSpanAnyValue = OtlpAnyValue +export type OtlpSpanKeyValue = OtlpKeyValue + +export interface OtlpSpanEvent { + name: string + timeUnixNano: string + attributes?: OtlpSpanKeyValue[] +} + +export interface OtlpSpanStatus { + /** unset 0, ok 1, error 2. */ + code: number + message?: string +} + +export interface OtlpSpan { + /** 32-char lowercase hex. */ + traceId: string + /** 16-char lowercase hex. */ + spanId: string + parentSpanId?: string + traceState?: string + name: string + /** unspecified 0, internal 1, server 2, client 3, producer 4, consumer 5. */ + kind: number + startTimeUnixNano: string + endTimeUnixNano: string + attributes?: OtlpSpanKeyValue[] + events?: OtlpSpanEvent[] + status?: OtlpSpanStatus + /** W3C trace flags in the low byte; the sampled bit is always set. */ + flags?: number +} + +export interface OtlpTracesPayload { + resourceSpans: Array<{ + resource: { attributes: OtlpSpanKeyValue[] } + scopeSpans: Array<{ + scope: { name: string; version?: string } + spans: OtlpSpan[] + }> + }> +} diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index c8f60426ef..cbaf105c46 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -795,6 +795,9 @@ importers: '@posthog-tooling/tsconfig-base': specifier: workspace:* version: link:../../tooling/tsconfig-base + '@posthog/types': + specifier: workspace:^ + version: link:../types '@rslib/core': specifier: 'catalog:' version: 0.10.6(@microsoft/api-extractor@7.58.9(@types/node@20.19.9))(typescript@5.9.3)