From 618ce2b9bf98c7dcb2cbdc671cf639fafddbbb01 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 1/7] feat(telemetry): add the OTLP pipeline, write-ahead cache and Cloud destination One pipeline per process implements the SPEC backend contract in TypeScript: the Cloud ingest derived from the server URL, the observability grant and exp read from the token, the token re-supplied on every refresh, and the collector-answer table (partial success, 413 split, Retry-After, 404 and owner opt-out silences, 401 holds with refused tokens remembered by fingerprint until they expire, 5xx backoff with jitter, permanent 4xx dropped and counted). Every record is stamped with its owner and its collection decision when captured, and export reads only the stamp. Batches are written to TelemetryStorage before the network is tried and removed once the collector has taken them; a refused write lands in a bounded memory fallback, an unreadable batch is kept for the next pass, a failed deletion is remembered so a delivered batch is never resent, and every loss is counted into a self-report of deltas. The OTLP encoder is a small protobuf writer, so no OpenTelemetry package ships; JWT and bearer values are masked in log bodies and span statuses, and the test-only collector override never carries a token. --- src/telemetry/otlp.ts | 278 ++++++++++++++ src/telemetry/pipeline.ts | 745 +++++++++++++++++++++++++++++++++++++ src/telemetry/storage.ts | 193 ++++++++++ src/telemetry/transport.ts | 164 ++++++++ 4 files changed, 1380 insertions(+) create mode 100644 src/telemetry/otlp.ts create mode 100644 src/telemetry/pipeline.ts create mode 100644 src/telemetry/storage.ts create mode 100644 src/telemetry/transport.ts diff --git a/src/telemetry/otlp.ts b/src/telemetry/otlp.ts new file mode 100644 index 0000000000..d657ec6983 --- /dev/null +++ b/src/telemetry/otlp.ts @@ -0,0 +1,278 @@ +/** + * OTLP on the wire: the two record shapes (plain and JSON-safe, so a cached batch is an array of + * them) and a protobuf writer for `ExportLogsServiceRequest` / `ExportTraceServiceRequest` — the + * binary form is the one the Cloud ingest and every collector agree on. + */ + +export type AttributeValue = string | number | boolean; +export type Attributes = Record; + +/** OTel severity numbers; nothing below `warn` leaves the device except `info` events (SPEC). */ +export const Severity = { info: 9, warn: 13, error: 17 } as const; +export type SeverityName = keyof typeof Severity; + +export const SpanKind = { internal: 1, client: 3 } as const; + +export interface LogRecord { + kind: 'log'; + timeMs: number; + severity: SeverityName; + /** `lk.*` / `custom.*` event name; absent for a plain log line. */ + eventName?: string; + body?: string; + attributes: Attributes; + traceId?: string; + spanId?: string; + /** The project the record belongs to; stamped when known, never changed after (SPEC ownership). */ + host?: string; +} + +export interface SpanRecord { + kind: 'span'; + name: string; + spanKind: number; + traceId: string; + spanId: string; + parentSpanId?: string; + startMs: number; + endMs: number; + /** OTel status: 0 unset (success and cancellation alike), 2 error. */ + status: 0 | 2; + statusMessage?: string; + attributes: Attributes; + events: Array<{ name: string; timeMs: number }>; + host?: string; +} + +export type TelemetryRecord = LogRecord | SpanRecord; + +const encoder = new TextEncoder(); + +class Writer { + private chunks: Uint8Array[] = []; + + private length = 0; + + private push(chunk: Uint8Array) { + this.chunks.push(chunk); + this.length += chunk.length; + } + + varint(value: number) { + const out: number[] = []; + let v = value; + while (v >= 0x80) { + out.push((v % 0x80) | 0x80); + v = Math.floor(v / 0x80); + } + out.push(v); + this.push(Uint8Array.from(out)); + } + + private tag(field: number, wire: number) { + this.varint((field << 3) | wire); + } + + uint(field: number, value: number) { + this.tag(field, 0); + this.varint(value); + } + + bytes(field: number, value: Uint8Array) { + if (value.length === 0) return; + this.tag(field, 2); + this.varint(value.length); + this.push(value); + } + + string(field: number, value: string) { + this.bytes(field, encoder.encode(value)); + } + + /** A `fixed64` of nanoseconds since the epoch, from milliseconds — exact in two 32-bit halves, no BigInt. */ + nanos(field: number, ms: number) { + const msHi = Math.floor(ms / 2 ** 32); + const low = (ms - msHi * 2 ** 32) * 1e6; + const lo32 = low % 2 ** 32; + const hi32 = msHi * 1e6 + Math.floor(low / 2 ** 32); + const bytes = new Uint8Array(8); + const view = new DataView(bytes.buffer); + view.setUint32(0, lo32, true); + view.setUint32(4, hi32, true); + this.tag(field, 1); + this.push(bytes); + } + + double(field: number, value: number) { + const bytes = new Uint8Array(8); + new DataView(bytes.buffer).setFloat64(0, value, true); + this.tag(field, 1); + this.push(bytes); + } + + message(field: number, write: (w: Writer) => void) { + const nested = new Writer(); + write(nested); + this.bytes(field, nested.finish()); + } + + finish(): Uint8Array { + const out = new Uint8Array(this.length); + let offset = 0; + for (const chunk of this.chunks) { + out.set(chunk, offset); + offset += chunk.length; + } + return out; + } +} + +function hexBytes(hex: string): Uint8Array { + const out = new Uint8Array(hex.length / 2); + for (let i = 0; i < out.length; i += 1) out[i] = Number.parseInt(hex.slice(i * 2, i * 2 + 2), 16); + return out; +} + +function anyValue(w: Writer, value: AttributeValue) { + if (typeof value === 'string') w.string(1, value); + else if (typeof value === 'boolean') w.uint(2, value ? 1 : 0); + else if (Number.isInteger(value) && value >= 0) w.uint(3, value); + else w.double(4, value); +} + +function attributes(w: Writer, field: number, attrs: Attributes) { + for (const [key, value] of Object.entries(attrs)) { + if (value === undefined) continue; + w.message(field, (kv) => { + kv.string(1, key); + kv.message(2, (v) => anyValue(v, value)); + }); + } +} + +const scope = (w: Writer) => { + w.string(1, 'livekit-telemetry'); + w.string(2, '0.1.0'); +}; + +/** `ExportLogsServiceRequest` / `ExportTraceServiceRequest` for records sharing one resource. */ +export function encode(records: TelemetryRecord[], resource: Attributes): Uint8Array { + const request = new Writer(); + request.message(1, (res) => { + res.message(1, (r) => attributes(r, 1, resource)); + res.message(2, (s) => { + s.message(1, scope); + for (const record of records) { + if (record.kind === 'log') s.message(2, (w) => logRecord(w, record)); + else s.message(2, (w) => span(w, record)); + } + }); + }); + return request.finish(); +} + +function logRecord(w: Writer, record: LogRecord) { + w.nanos(1, record.timeMs); + w.uint(2, Severity[record.severity]); + w.string(3, record.severity.toUpperCase()); + if (record.body !== undefined) w.message(5, (v) => anyValue(v, record.body!)); + attributes(w, 6, record.attributes); + if (record.traceId) w.bytes(9, hexBytes(record.traceId)); + if (record.spanId) w.bytes(10, hexBytes(record.spanId)); + w.nanos(11, record.timeMs); + if (record.eventName) w.string(12, record.eventName); +} + +function span(w: Writer, record: SpanRecord) { + w.bytes(1, hexBytes(record.traceId)); + w.bytes(2, hexBytes(record.spanId)); + if (record.parentSpanId) w.bytes(4, hexBytes(record.parentSpanId)); + w.string(5, record.name); + w.uint(6, record.spanKind); + w.nanos(7, record.startMs); + w.nanos(8, record.endMs); + attributes(w, 9, record.attributes); + for (const event of record.events) { + w.message(11, (e) => { + e.nanos(1, event.timeMs); + e.string(2, event.name); + }); + } + if (record.status) { + w.message(15, (s) => { + if (record.statusMessage) s.string(2, record.statusMessage); + s.uint(3, record.status); + }); + } +} + +/** How many records a 2xx answer still rejected (`partial_success`), `0` for an empty body. */ +export function rejectedRecords(body: Uint8Array): number { + // ExportXServiceResponse { partial_success = 1 { rejected_x = 1 (int64) } }, fields in any order + const fields = (bytes: Uint8Array) => { + const out = new Map(); + let i = 0; + const varint = () => { + let value = 0; + let scale = 1; + while (i < bytes.length) { + const byte = bytes[i]; + i += 1; + value += (byte & 0x7f) * scale; + scale *= 0x80; + if (byte < 0x80) break; + } + return value; + }; + while (i < bytes.length) { + const tag = varint(); + const field = Math.floor(tag / 8); + switch (tag & 7) { + case 0: + out.set(field, varint()); + break; + case 1: + i += 8; + break; + case 2: { + const length = varint(); + out.set(field, bytes.subarray(i, i + length)); + i += length; + break; + } + case 5: + i += 4; + break; + default: + return out; // unknown wire type: stop reading, report what was found + } + } + return out; + }; + const partial = fields(body).get(1); + const rejected = partial instanceof Uint8Array ? fields(partial).get(1) : undefined; + return typeof rejected === 'number' ? rejected : 0; +} + +/** A JWT or bearer value never leaves the device inside a message or a span status (SPEC). */ +export const mask = (text: string) => + text + .replace(/eyJ[\w-]+\.[\w-]+\.[\w-]+/g, '') + .replace(/(bearer\s+)[\w.~+/=-]+/gi, '$1'); + +/** A timer that must not keep a Node host (SSR, tests) alive. */ +export function unref(timer: T): T { + (timer as { unref?: () => void })?.unref?.(); + return timer; +} + +/** Unique, not unguessable: ids need no entropy guarantees, and this works without a crypto polyfill. */ +export function randomHex(bytes: number): string { + const buffer = new Uint8Array(bytes); + if (globalThis.crypto?.getRandomValues) { + globalThis.crypto.getRandomValues(buffer); + } else { + for (let i = 0; i < bytes; i += 1) buffer[i] = Math.floor(Math.random() * 256); + } + return Array.from(buffer, (byte) => byte.toString(16).padStart(2, '0')).join(''); +} diff --git a/src/telemetry/pipeline.ts b/src/telemetry/pipeline.ts new file mode 100644 index 0000000000..c6b2310d7d --- /dev/null +++ b/src/telemetry/pipeline.ts @@ -0,0 +1,745 @@ +/** + * The process-wide pipeline: one queue, a write-ahead cache of batches, one request in flight, and + * SPEC's upload policy — telemetry never wins over media. Each record is stamped with its project + * when captured and never re-routed; each project keeps its own token, pause and silence. + */ +import log from '../logger'; +import { type DeviceState, cadenceFactor, changes, softHold } from './device'; +import { + type Attributes, + type LogRecord, + type SeverityName, + type TelemetryRecord, + encode, + randomHex, + rejectedRecords, + unref, +} from './otlp'; +import { type Owner, type TelemetryScope, scheduled } from './scope'; +import { + type BatchMeta, + MemoryStorage, + type TelemetryStorage, + WriteAheadCache, + batchId, + decodeBatch, + encodeBatch, + parseBatchId, +} from './storage'; +import { + type Answer, + EXPORT_TIMEOUT_MS, + backoffMs, + classify, + cloudHost, + fingerprint, + ingestUrl, + post, + readToken, +} from './transport'; + +export const FLUSH_INTERVAL_MS = 60_000; +export const STATS_WINDOW_MS = 60_000; +const MAX_QUEUE = 2048; +const MAX_BATCH = 512; +const MAX_CACHE_BYTES = 4 * 1024 * 1024; +const MAX_CACHE_BATCHES = 512; +/** A request never carries more than this much encoded protobuf (SPEC); a bigger batch is halved like a 413. */ +const MAX_BATCH_BYTES = 1024 * 1024; +/** Failed-delete markers at most: the combined store bound (the store's batches plus the memory fallback's). */ +const MAX_DELETING = 2 * MAX_CACHE_BATCHES; +/** While a Room is in a call, a backlog replays at this many requests per interval (SPEC budget). */ +const MAX_BATCHES_PER_UPLOAD = 4; +const HOLD_CAP_MS = 60_000; +const DAY_MS = 24 * 60 * 60 * 1000; +const FLOOD_LIMIT = 300; +const FLOOD_WINDOW_MS = 10 * 60_000; + +interface Project { + token?: string; + expiresAt?: number; + /** `false` after a first token without the grant: the project never opted in. */ + granted?: boolean; + /** Fingerprints of tokens the collector refused → their expiry; never the token itself, never forgotten before it. */ + refused: Map; + pausedUntil: number; + failures: number; + /** `process` after the owner's opt-out answer; `token` after a 404, until the next token. */ + silent?: 'process' | 'token'; +} + +export class Pipeline { + readonly processTraceId = randomHex(16); + + resource: Attributes = {}; + + private cache: TelemetryStorage = new MemoryStorage(MAX_CACHE_BYTES, MAX_CACHE_BATCHES); + + /** A host's store gets a bounded memory fallback for the batches it refuses (SPEC: kept in memory, counted as write errors). */ + set storage(store: TelemetryStorage) { + this.cache = new WriteAheadCache(store, MAX_CACHE_BYTES, MAX_CACHE_BATCHES, () => + this.count('cache.write_errors'), + ); + } + + get storage(): TelemetryStorage { + return this.cache; + } + + /** Local e2e runs point everything here (the `LK_TELEMETRY_ENDPOINT` of the native cores): no Cloud rules, no tokens. */ + endpoint?: string; + + /** Test tap: every batch as it is cached. */ + onBatch?: (records: TelemetryRecord[]) => void; + + /** Rooms in a call, held strongly: they meter uploads and drive the cadence. */ + readonly scopes = new Set(); + + /** Every Room's scope, weakly: telemetry never retains a Room nobody uses, and the opt-out still reaches them all. */ + private tracked = new Set>(); + + /** Batches the collector took but the store would not delete yet: never sent again, deleted at the next chance. */ + private deleting = new Set(); + + private reaper = + typeof FinalizationRegistry === 'undefined' + ? undefined + : new FinalizationRegistry>((ref) => this.tracked.delete(ref)); + + /** Fails closed on a runtime without `WeakRef` (none of the supported browsers; Hermes has it): nothing is registered or captured. */ + disabled = typeof WeakRef === 'undefined'; + + private queue: Array<{ record: TelemetryRecord; scope?: TelemetryScope; owner?: Owner }> = []; + + /** At this many markers nothing new is sent: an accepted batch is never forgotten to make room. */ + private markerCap = MAX_DELETING; + + /** Times the next CPU-limited expiry, so cadence relief never waits for a tick. */ + private relief?: ReturnType; + + private projects = new Map(); + + private latestHost?: string; + + private warned = new Set(); + + private timer?: ReturnType; + + private flushing?: Promise; + + private inFlight?: AbortController; + + private allowance = MAX_BATCHES_PER_UPLOAD; + + private holds = new Set(); + + private holdSince = 0; + + private device: DeviceState = {}; + + private cadence = 1; + + private counters: Record = {}; + + private reported: Record = {}; + + private reportDue = false; + + private floodCount = 0; + + private floodWindowStart = 0; + + private sequence = 0; + + get enabled() { + return !this.disabled; + } + + /** SPEC's cadence factor right now: the device state × an encoder CPU-limited within the minute, capped at 4. */ + get factor(): number { + const now = Date.now(); + const cpu = Array.from(this.scopes).some((scope) => scope.cpuLimitedUntil > now) ? 2 : 1; + return Math.min(4, cadenceFactor(this.device) * cpu); + } + + get statsWindowMs() { + return STATS_WINDOW_MS * this.factor; + } + + start() { + if (this.timer || this.disabled) return; + this.timer = unref(setInterval(() => this.tick(), FLUSH_INTERVAL_MS * this.cadence)); + } + + stop() { + clearInterval(this.timer); + this.timer = undefined; + } + + private tick() { + this.allowance = MAX_BATCHES_PER_UPLOAD; + this.applyCadence(); + this.flush().catch(() => {}); + } + + /** @internal */ + count(key: string, by = 1) { + this.counters[key] = (this.counters[key] ?? 0) + by; + if (!key.startsWith('uploads.sent') && key !== 'uploads.bytes') this.reportDue = true; + } + + /** A record that is nobody's call — device state, capture failures, pre-room warnings — under the process scope. */ + private processRecord(record: Pick & Partial) { + this.record({ + kind: 'log', + timeMs: Date.now(), + traceId: this.processTraceId, + ...record, + attributes: { 'session.id': this.processTraceId, ...record.attributes }, + }); + } + + emit(eventName: string, attributes: Attributes = {}, severity: SeverityName = 'info') { + const withName = { 'otel.event.name': eventName, ...attributes }; + this.processRecord({ severity, eventName, body: eventName, attributes: withName }); + } + + log(severity: 'warn' | 'error', body: string, logger: string) { + const attributes = { 'lk.log.source': 'sdk', 'lk.log.logger': logger }; + this.processRecord({ severity, body, attributes }); + } + + /** + * @internal Discrete events are rationed (SPEC flood guard); stats windows and the report are + * exempt. A record keeps the decision stamped on its owner when it opened: a self-hosted owner's + * record is dropped here and counted (a policy loss, local only — SPEC), a Cloud owner's goes to + * that project, an unassigned one waits for its Room's first project (`adopt`). Process records + * go to the latest project. + */ + record(record: TelemetryRecord, scope?: TelemetryScope, exempt = false, owner?: Owner) { + if (this.disabled) return; + if (owner?.collects === false) { + this.count('policy.no_ingest'); + return; + } + if (!exempt && !this.floodOk()) return; + record.host ??= owner ? owner.host : this.latestHost; + this.queue.push({ record, scope, owner }); + const overflow = this.queue.length - MAX_QUEUE; + if (overflow > 0) { + this.queue.splice(0, overflow); + this.count('dropped.queue_full', overflow); + } + } + + private floodOk(): boolean { + if (Date.now() - this.floodWindowStart > FLOOD_WINDOW_MS) { + this.floodWindowStart = Date.now(); + this.floodCount = 0; + } + this.floodCount += 1; + if (this.floodCount <= FLOOD_LIMIT) return true; + this.count('dropped.rate_limited'); + return false; + } + + private project(host: string): Project { + const fresh: Project = { refused: new Map(), pausedUntil: 0, failures: 0 }; + return this.projects.get(host) ?? this.projects.set(host, fresh).get(host)!; + } + + /** @internal A Room exists. Only dead references are ever pruned: a live Room is always reachable for the purge. */ + track(scope: TelemetryScope) { + if (this.disabled) return; + const ref = new WeakRef(scope); + this.tracked.add(ref); + if (this.reaper) this.reaper.register(scope, ref); + else for (const old of Array.from(this.tracked)) if (!old.deref()) this.tracked.delete(old); + } + + /** @internal The Room is in a call. */ + activate(scope: TelemetryScope) { + this.scopes.add(scope); + } + + /** @internal The Room left for good: no longer in a call, and its CPU weight leaves the cadence with it. */ + forget(scope: TelemetryScope) { + this.scopes.delete(scope); + this.applyCadence(); + } + + private live(): Set { + const all = new Set(this.scopes); + for (const ref of this.tracked) { + const scope = ref.deref(); + if (scope) all.add(scope); + } + return all; + } + + /** + * A Room's server URL and token (SPEC "Destination and credentials"). Returns the project host + * the Room is routed to, `''` under the collector override, `undefined` when the host has no + * ingest. + */ + setServer(serverUrl: string, token: string, scope?: TelemetryScope): string | undefined { + if (this.disabled) return undefined; // no credential is taken after the opt-out + if (this.endpoint !== undefined) { + this.project(''); + this.adopt(scope, ''); + return ''; + } + const host = cloudHost(serverUrl); + if (!host) { + // One local line (SPEC): a self-hosted or OSS server has no ingest for this Room's records. + if (!this.warned.has(serverUrl)) + log.info(`telemetry: no LiveKit Cloud ingest for ${serverUrl}`); + this.warned.add(serverUrl); + this.adopt(scope, undefined); + return undefined; + } + const project = this.project(host); + const claims = readToken(token); + // The first token decides whether the project opted in (SPEC); a later token without the + // grant does not replace a granted one that is still valid. + project.granted ??= claims.granted; + if (project.granted && claims.granted && !claims.expired && !this.refused(project, token)) { + project.token = token; + project.expiresAt = claims.expiresAt; + } + if (project.silent === 'token') project.silent = undefined; + this.adopt(scope, host); + this.wake(); + return host; + } + + /** + * A Room's records captured before it had a server are resolved by its first one (SPEC): a Cloud + * project takes them, a self-hosted server has no ingest so they are dropped and counted now — + * nothing unassigned outlives the first resolution. Process records take the latest project. + */ + private adopt(scope: TelemetryScope | undefined, host: string | undefined) { + if (host !== undefined) this.latestHost = host; + this.queue = this.queue.filter((entry) => { + if (entry.record.host !== undefined) return true; + if (scope !== undefined && entry.scope === scope && entry.owner?.collects === undefined) { + if (host === undefined) { + this.count('policy.no_ingest'); + return false; + } + entry.record.host = host; + } else if (entry.scope === undefined && host !== undefined) { + entry.record.host = host; + } + return true; + }); + } + + /** The store's listing, or nothing while the store is unavailable (gauges and purges wait). */ + private listed(): string[] { + try { + return this.storage.pending(); + } catch { + return []; + } + } + + /** The token to send, if it is still valid and was never refused. */ + private usableToken(project: Project): string | undefined { + const { token, expiresAt } = project; + const valid = + token && !this.refused(project, token) && (expiresAt === undefined || expiresAt > Date.now()); + return valid ? token : undefined; + } + + /** + * A refused token is known by fingerprint until it expires — one without `exp` for the process — + * and never forgotten before that (SPEC). The bound is the number of distinct refused tokens + * still alive, a few per hour at the SFU's refresh cadence. + */ + private refused(project: Project, token: string): boolean { + for (const [print, until] of Array.from(project.refused)) { + if (until <= Date.now()) project.refused.delete(print); + } + return project.refused.has(fingerprint(token)); + } + + private refuse(project: Project, token: string) { + const until = readToken(token).expiresAt ?? Number.POSITIVE_INFINITY; + project.refused.set(fingerprint(token), until); + } + + /** A soft hold from a span that owns the uplink (`lk.connect`, `lk.reconnect`). */ + hold(owner: object, up: boolean) { + if (up) this.holds.add(owner); + else this.holds.delete(owner); + } + + /** Soft holds last at most 60 s on their own clock; then one batch goes out and the hold starts over. */ + private held(): boolean { + if (this.holds.size === 0 && !softHold(this.device)) { + this.holdSince = 0; + return false; + } + const now = Date.now(); + if (!this.holdSince) this.holdSince = now; + if (now - this.holdSince >= HOLD_CAP_MS) { + this.count('holds.capped'); + this.holdSince = now; + return false; + } + return true; + } + + /** What the platform now says about the device: events on change, the cadence, a flush on background. */ + deviceState(state: DeviceState) { + const next = { ...this.device, ...state }; + for (const [event, attributes] of changes(this.device, next)) this.emit(event, attributes); + const toBackground = next.appState === 'background' && this.device.appState !== 'background'; + this.device = next; + this.applyCadence(); + if (toBackground) { + for (const scope of this.scopes) scope.closeWindows(); + this.flush(true).catch(() => {}); + } + } + + /** Re-arms the export timer and every Room's deadlines when the factor changed: a shorter period applies at once (SPEC). */ + applyCadence() { + const { factor } = this; + // The next CPU-limited expiry re-derives the factor by itself: relief never waits for a tick. + clearTimeout(this.relief); + const now = Date.now(); + const expiries = Array.from(this.scopes, (scope) => scope.cpuLimitedUntil).filter( + (at) => at > now, + ); + if (expiries.length > 0) { + const wait = Math.min(...expiries) - now + 1; + this.relief = unref( + setTimeout( + scheduled(() => this.applyCadence()), + wait, + ), + ); + } + if (factor === this.cadence) return; + this.cadence = factor; + for (const scope of Array.from(this.live())) scope.cadenceChanged(); + // Restarting the timer is what makes a shorter period apply at once (SPEC). + if (this.timer) { + this.stop(); + this.start(); + } + } + + private inCall(): boolean { + return Array.from(this.scopes).some((scope) => scope.inCall); + } + + private wake() { + unref(setTimeout(() => this.flush().catch(() => {}), 0)); + } + + /** Cache what is queued, then send what the policy allows; `force` (background, page hide) drains without the budget and the holds. */ + async flush(force = false): Promise { + // One pass at a time; a flush asked for during a pass runs right after it, never skipped. + while (this.flushing) await this.flushing; + if (this.disabled) return; + this.flushing = this.pass(force).finally(() => { + this.flushing = undefined; + }); + await this.flushing; + } + + private async pass(force: boolean): Promise { + if (force) this.reportDue = true; + this.persist(force); + let budget = force || !this.inCall() ? Number.POSITIVE_INFINITY : this.allowance; + let pending: string[]; + try { + pending = this.storage.pending(); + } catch { + this.count('cache.list_errors'); // the store is unavailable: nothing reconciled, nothing sent + return; + } + // A marker whose batch left the store (evicted, or removed behind our back) is spent. + for (const id of Array.from(this.deleting)) if (!pending.includes(id)) this.deleting.delete(id); + for (let i = 0; i < pending.length && budget > 0 && !this.disabled; i += 1) { + const id = pending[i]; + if (this.deleting.has(id)) { + this.discard(id); // taken by the collector already: deleted now if the store lets us, never re-sent + continue; + } + const meta = parseBatchId(id); + let body: Uint8Array | undefined; + try { + body = this.storage.read(id); + } catch { + this.count('cache.read_errors'); // the store cannot serve it right now: kept for the next pass + continue; + } + const expired = meta && Date.now() - meta.timeMs > DAY_MS; + if (!meta || body === undefined || expired) { + this.discard(id); + if (expired) this.count('dropped.expired', meta.records); + continue; + } + // The policy is evaluated before every request (SPEC): holds pause everything, a project's + // own pause, silence or missing token only its batches. + const offline = typeof navigator !== 'undefined' && navigator.onLine === false; + if (!force && (offline || this.held())) break; + const project = this.project(meta.host); + // The collector override never sees a bearer, cached Cloud batches included. + const token = this.endpoint === undefined ? this.usableToken(project) : undefined; + const paused = project.silent || !token || project.pausedUntil > Date.now(); + if (this.endpoint === undefined && paused) continue; + let records: TelemetryRecord[]; + try { + records = decodeBatch(body); + } catch { + this.discard(id); + this.count('dropped.corrupt', meta.records); + continue; + } + // At the marker cap nothing new goes out: an accepted batch is never forgotten to make room. + if (this.deleting.size >= this.markerCap) break; + budget -= 1; + this.allowance = Math.max(0, this.allowance - 1); + const url = + this.endpoint !== undefined + ? `${this.endpoint.replace(/\/$/, '')}/v1/${meta.kind}` + : ingestUrl(meta.host, meta.kind); + const answer = await this.send(url, records, token); + // An answer that lands after the opt-out is dropped: the purge already ran. + if (this.disabled) break; + const halves = this.settle(id, meta, records, project, token, answer); + if (halves) pending.splice(i + 1, 0, ...halves); + } + } + + private persist(force = false) { + const groups = new Map(); + const waiting: typeof this.queue = []; + for (const entry of this.queue) { + // Only the owner stamped at capture routes a record; a Room's records wait for its first + // project, a non-Cloud Room's are dropped at the door. + const { host } = entry.record; + if (host === undefined) { + waiting.push(entry); + continue; + } + const project = this.projects.get(host); + if (project?.granted === false || project?.silent === 'process') continue; // never opted in, or opted out + const key = `${host}|${entry.record.kind === 'span' ? 'traces' : 'logs'}`; + groups.set(key, [...(groups.get(key) ?? []), entry.record]); + } + this.queue = waiting; + // The self-report rides in the next logs batch, never a request of its own — except the + // session summary at shutdown (SPEC). + if (this.reportDue) { + const logsKey = Array.from(groups.keys()).find((key) => key.endsWith('|logs')); + const host = this.endpoint !== undefined ? '' : this.latestHost; + if (logsKey) groups.get(logsKey)!.push(this.report()); + else if (force && host !== undefined) groups.set(`${host}|logs`, [this.report()]); + } + for (const [key, records] of groups) { + const [host, kind] = key.split('|') as [string, BatchMeta['kind']]; + for (let i = 0; i < records.length; i += MAX_BATCH) { + const batch = records.slice(i, i + MAX_BATCH); + this.onBatch?.(batch); + this.store({ timeMs: Date.now(), records: batch.length, kind, host }, batch); + } + } + } + + /** Writes a batch or throws; what the cache evicts to take it is counted as lost. */ + private put(meta: BatchMeta, records: TelemetryRecord[]): string { + if (this.disabled) throw new Error('telemetry disabled'); // nothing is written after the opt-out + const id = batchId(meta, (this.sequence += 1)); + for (const evicted of this.storage.put(id, encodeBatch(records))) { + // The store's eviction list is the authority: an uploaded batch leaving it is no loss. + if (!this.deleting.delete(evicted)) { + this.count('dropped.cache_full', parseBatchId(evicted)?.records ?? 0); + } + } + return id; + } + + /** A batch the cache cannot take at all (not even the memory fallback) is counted once as lost. */ + private store(meta: BatchMeta, records: TelemetryRecord[]): string | undefined { + try { + return this.put(meta, records); + } catch { + if (!this.disabled) this.count('dropped.cache_error', records.length); + return undefined; + } + } + + private async send( + url: string, + records: TelemetryRecord[], + token: string | undefined, + ): Promise { + const controller = new AbortController(); + this.inFlight = controller; + const timeout = unref(setTimeout(() => controller.abort('timeout'), EXPORT_TIMEOUT_MS)); + const encoded = encode(records, this.resource); + if (encoded.byteLength > MAX_BATCH_BYTES) { + clearTimeout(timeout); + this.inFlight = undefined; + return { kind: 'oversized', bytes: 0 }; // halved like a 413, before any request + } + try { + const raw = await post(url, encoded, token, controller.signal); + let rejected = 0; + try { + if (raw.status < 300) rejected = rejectedRecords(raw.body); + } catch { + // an unreadable success body is still a success + } + const body = raw.status >= 400 ? new TextDecoder().decode(raw.body) : ''; + return { ...classify(raw.status, raw.retryAfter, body, rejected), bytes: raw.sent }; + } catch { + if (controller.signal.reason === 'timeout') this.count('uploads.timeouts'); + return { kind: 'retry', bytes: 0 }; + } finally { + clearTimeout(timeout); + this.inFlight = undefined; + } + } + + /** Applies the collector's answer (SPEC table); returns the ids of a 413 split's halves. */ + private settle( + id: string, + meta: BatchMeta, + records: TelemetryRecord[], + project: Project, + token: string | undefined, + answer: Answer & { bytes: number }, + ): string[] | undefined { + switch (answer.kind) { + case 'accepted': + this.discard(id); + this.count('uploads.sent'); + this.count('uploads.bytes', answer.bytes); + if (answer.rejected > 0) this.count('dropped.rejected', answer.rejected); + project.failures = 0; + break; + case 'rejected': + this.discard(id); + this.count('dropped.rejected', records.length); + break; + case 'oversized': { + if (records.length === 1) { + this.discard(id); + this.count('dropped.oversized', 1); + break; + } + // One step: both halves take the parent's place, or nothing changes and the parent stays + // whole — nothing else is evicted in between (SPEC). A parent the cache cannot split now + // waits for the project's backoff, like a failed upload. + const half = Math.ceil(records.length / 2); + const parts = [records.slice(0, half), records.slice(half)].map( + (part): [string, Uint8Array] => [ + batchId({ ...meta, records: part.length }, (this.sequence += 1)), + encodeBatch(part), + ], + ); + let replaced: boolean; + try { + replaced = !this.disabled && (this.storage.replace?.(id, parts) ?? false); + } catch { + replaced = false; + } + if (replaced) return parts.map(([partId]) => partId); + // A store without a transactional `replace` (see `TelemetryStorage`) keeps the parent whole. + project.failures += 1; + project.pausedUntil = Date.now() + backoffMs(project.failures); + this.count('uploads.failed'); + break; + } + case 'disabled': + case 'gone': + this.purgeProject(meta.host); + project.silent = answer.kind === 'disabled' ? 'process' : 'token'; + break; + case 'unauthorized': + if (token) this.refuse(project, token); + this.count('uploads.unauthorized'); + break; + default: + if (answer.kind === 'retry') project.failures += 1; + project.pausedUntil = + Date.now() + (answer.kind === 'pause' ? answer.forMs : backoffMs(project.failures)); + this.count('uploads.failed'); + } + return undefined; + } + + private purgeProject(host: string) { + for (const id of this.listed()) { + if (parseBatchId(id)?.host === host) this.discard(id); + } + } + + /** Deletes a batch, or remembers to: a batch the collector took is never sent twice from this launch. */ + private discard(id: string) { + try { + this.storage.remove(id); + this.deleting.delete(id); + } catch { + if (!this.deleting.has(id)) this.count('cache.delete_errors'); + this.deleting.add(id); + } + } + + /** `lk.telemetry.report`: counts since the previous report, plus the cache gauge (SPEC). */ + private report(): LogRecord { + this.reportDue = false; + const attributes: Attributes = { + 'session.id': this.processTraceId, + 'otel.event.name': 'lk.telemetry.report', + 'lk.telemetry.cache.batches': this.listed().length, + }; + const always = ['uploads.sent', 'uploads.bytes', 'uploads.failed']; + for (const key of new Set([...always, ...Object.keys(this.counters)])) { + if (key.startsWith('policy.')) continue; // losses by policy are local only (SPEC) + const delta = (this.counters[key] ?? 0) - (this.reported[key] ?? 0); + if (delta || always.includes(key)) attributes[`lk.telemetry.${key}`] = delta; + } + this.reported = { ...this.counters }; + return { + kind: 'log', + timeMs: Date.now(), + severity: 'info', + eventName: 'lk.telemetry.report', + body: 'lk.telemetry.report', + attributes, + traceId: this.processTraceId, + }; + } + + /** The opt-out, in effect when this returns: nothing is captured, everything unsent is deleted, no credential is kept. */ + disable() { + this.disabled = true; + this.stop(); + clearTimeout(this.relief); + this.queue = []; + this.holds.clear(); + this.inFlight?.abort('disabled'); + for (const scope of Array.from(this.live())) scope.purge(); + this.scopes.clear(); + this.tracked.clear(); + this.deleting.clear(); + this.projects.clear(); + try { + this.storage.clear(); + } catch { + // a store that cannot clear keeps what it has; nothing new ever reaches it + } + } + + stats(): Record { + return { ...this.counters, queued: this.queue.length, cached: this.listed().length }; + } +} diff --git a/src/telemetry/storage.ts b/src/telemetry/storage.ts new file mode 100644 index 0000000000..929817d978 --- /dev/null +++ b/src/telemetry/storage.ts @@ -0,0 +1,193 @@ +/** + * The write-ahead cache: a batch is stored before the network is tried and removed only when the + * collector took it. Synchronous on purpose; React Native supplies a file-backed one. + */ +import type { TelemetryRecord } from './otlp'; + +/** + * @internal The write-ahead cache a host supplies (React Native: a directory of files). A call that + * cannot reach the store right now throws; `read` returning `undefined` means the batch is gone. + */ +export interface TelemetryStorage { + /** Store a batch; returns the ids evicted to stay inside the store's own bounds. */ + put(id: string, body: Uint8Array): string[]; + /** Stored ids, oldest first. */ + pending(): string[]; + read(id: string): Uint8Array | undefined; + remove(id: string): void; + clear(): void; + /** + * Swap one batch for its parts in a single step, or change nothing and return `false` when they + * would not fit (a 413 split: nothing else evicted in between). A store without it never splits: + * the batch stays whole and waits. + */ + replace?(id: string, parts: Array<[string, Uint8Array]>): boolean; +} + +export interface BatchMeta { + timeMs: number; + records: number; + kind: 'logs' | 'traces'; + /** The project the batch belongs to; empty under the collector override. */ + host: string; +} + +/** Ids sort oldest first as plain strings and carry what a store written by an earlier launch needs. */ +export function batchId(meta: BatchMeta, sequence: number): string { + return [ + String(meta.timeMs).padStart(15, '0'), + String(sequence).padStart(6, '0'), + meta.records, + meta.kind === 'logs' ? 'l' : 't', + meta.host, + ].join('_'); +} + +export function parseBatchId(id: string): BatchMeta | undefined { + const [time, , records, kind, ...host] = id.split('_'); + if (kind !== 'l' && kind !== 't') return undefined; + return { + timeMs: Number(time), + records: Number(records) || 0, + kind: kind === 'l' ? 'logs' : 'traces', + host: host.join('_'), + }; +} + +export const encodeBatch = (records: TelemetryRecord[]): Uint8Array => + new TextEncoder().encode(JSON.stringify(records)); + +/** A cached body back into records; anything but an array of log/span records is corrupt. */ +export const decodeBatch = (body: Uint8Array): TelemetryRecord[] => { + const records: unknown = JSON.parse(new TextDecoder().decode(body)); + const shaped = + Array.isArray(records) && + records.every( + (r) => + r !== null && + typeof r === 'object' && + (r.kind === 'log' || r.kind === 'span') && + typeof r.attributes === 'object', + ); + if (!shaped) throw new Error('not a batch'); + return records as TelemetryRecord[]; +}; + +/** + * A host's store behind a bounded memory fallback: a batch the disk refuses is kept in memory and + * counted as a write error, lost only when the fallback's own bound evicts it (SPEC "Durability"). + * A store that cannot list or read right now throws, so nothing is reconciled or deleted against + * it; the next pass tries again. + */ +export class WriteAheadCache implements TelemetryStorage { + private fallback: MemoryStorage; + + constructor( + private primary: TelemetryStorage, + maxBytes: number, + maxBatches: number, + private onWriteError: () => void, + ) { + // ponytail: the fallback has the cache's own budget rather than sharing the disk's live size + // (a store exposes no size); the two together stay within twice the bound. + this.fallback = new MemoryStorage(maxBytes, maxBatches); + } + + private quiet(run: () => T, fallback: T): T { + try { + return run(); + } catch { + return fallback; + } + } + + put(id: string, body: Uint8Array): string[] { + try { + return this.primary.put(id, body); + } catch { + this.onWriteError(); + return this.fallback.put(id, body); + } + } + + /** A listing the store cannot serve throws: nothing is reconciled against an unavailable store. */ + pending(): string[] { + return [...this.primary.pending(), ...this.fallback.pending()].sort(); + } + + read(id: string): Uint8Array | undefined { + return this.fallback.read(id) ?? this.primary.read(id); + } + + replace(id: string, parts: Array<[string, Uint8Array]>): boolean { + if (this.fallback.read(id) !== undefined) return this.fallback.replace(id, parts); + // Only a store with its own transaction splits; anything else leaves the batch whole. + return this.primary.replace ? this.quiet(() => this.primary.replace!(id, parts), false) : false; + } + + /** A deletion the store refuses throws: the batch is then remembered as taken and never sent again. */ + remove(id: string) { + this.fallback.remove(id); + this.primary.remove(id); + } + + clear() { + this.fallback.clear(); + this.primary.clear(); + } +} + +/** Lost with the tab; bounded by bytes and by count, the oldest evicted first; one is kept unless it alone is over the bytes. */ +export class MemoryStorage implements TelemetryStorage { + private batches: Array<[string, Uint8Array]> = []; + + constructor( + private maxBytes: number, + private maxBatches: number, + ) {} + + put(id: string, body: Uint8Array): string[] { + this.batches.push([id, body]); + const evicted: string[] = []; + let total = this.batches.reduce((sum, [, batch]) => sum + batch.byteLength, 0); + while ( + (total > this.maxBytes || this.batches.length > this.maxBatches) && + (this.batches.length > 1 || total > this.maxBytes) + ) { + const [oldest, batch] = this.batches.shift()!; + total -= batch.byteLength; + evicted.push(oldest); + } + return evicted; + } + + /** Both parts take the batch's place, or nothing changes: no eviction in between (SPEC 413 split). */ + replace(id: string, parts: Array<[string, Uint8Array]>): boolean { + const at = this.batches.findIndex(([key]) => key === id); + if (at < 0) return false; + const bytes = (list: Array<[string, Uint8Array]>) => + list.reduce((sum, [, body]) => sum + body.byteLength, 0); + const total = bytes(this.batches) - this.batches[at][1].byteLength + bytes(parts); + if (total > this.maxBytes || this.batches.length - 1 + parts.length > this.maxBatches) { + return false; + } + this.batches.splice(at, 1, ...parts); + return true; + } + + pending(): string[] { + return this.batches.map(([id]) => id); + } + + read(id: string): Uint8Array | undefined { + return this.batches.find(([key]) => key === id)?.[1]; + } + + remove(id: string) { + this.batches = this.batches.filter(([key]) => key !== id); + } + + clear() { + this.batches = []; + } +} diff --git a/src/telemetry/transport.ts b/src/telemetry/transport.ts new file mode 100644 index 0000000000..c9371bb5c3 --- /dev/null +++ b/src/telemetry/transport.ts @@ -0,0 +1,164 @@ +/** + * The backend contract (SPEC "Destination and credentials", "Collector answers"): where a server URL + * points telemetry to, what a token says about that project, the request, and what each answer means. + */ +import { decodeJwt } from 'jose'; + +const CLOUD_SUFFIX = '.livekit.cloud'; +const DAY_MS = 24 * 60 * 60 * 1000; +const THROTTLE_DEFAULT_MS = 60_000; +const BACKOFF_CAP_MS = 60_000; +const KEEPALIVE_LIMIT = 60 * 1024; // browsers cap all in-flight `keepalive` bodies at 64 KiB together +const DISABLED_ANSWER = 'data recording is disabled by owner'; +export const EXPORT_TIMEOUT_MS = 10_000; + +/** `wss://.livekit.cloud/…` → that host (WHATWG-parsed: TLS, no userinfo, default port); anything else has no ingest. */ +export function cloudHost(serverUrl: string): string | undefined { + let url: URL; + try { + url = new URL(serverUrl); + } catch { + return undefined; + } + if (url.protocol !== 'wss:' && url.protocol !== 'https:') return undefined; + if (url.username || url.password || url.port) return undefined; + return url.hostname.endsWith(CLOUD_SUFFIX) ? url.hostname : undefined; +} + +export const ingestUrl = (host: string, kind: 'logs' | 'traces') => + `https://${host}/observability/client/${kind}/otlp/v0`; + +export interface TokenClaims { + /** `observability.write` or `observability.clientWrite`. */ + granted: boolean; + expiresAt?: number; + expired: boolean; +} + +/** The token's *unverified* claims. Malformed, past, negative or non-numeric `exp` → expired. */ +export function readToken(token: string): TokenClaims { + try { + const claims = decodeJwt(token) as { + exp?: unknown; + observability?: { write?: unknown; clientWrite?: unknown }; + }; + let expiresAt: number | undefined; + if (claims.exp !== undefined) { + expiresAt = typeof claims.exp === 'number' && claims.exp > 0 ? claims.exp * 1000 : 0; + } + return { + granted: claims.observability?.write === true || claims.observability?.clientWrite === true, + expiresAt, + expired: expiresAt !== undefined && expiresAt <= Date.now(), + }; + } catch { + return { granted: false, expired: true }; + } +} + +/** + * What a collector answer means (SPEC table): `rejected` drops the batch (400, 3xx, other 4xx/5xx), + * `oversized` halves it (413), `disabled` purges the project for the process (401/403 naming the + * owner's opt-out), `unauthorized` holds it and retires the token (other 401/403), `gone` purges the + * project until its next token (404), `pause` waits a named delay (429, 5xx with Retry-After), + * `retry` waits the local backoff (502/503/504, no answer). + */ +export type Answer = + | { kind: 'accepted'; rejected: number } + | { kind: 'rejected' } + | { kind: 'oversized' } + | { kind: 'disabled' } + | { kind: 'unauthorized' } + | { kind: 'gone' } + | { kind: 'pause'; forMs: number } + | { kind: 'retry' }; + +export function classify( + status: number, + retryAfter: string | null, + body: string, + rejected = 0, +): Answer { + if (status >= 200 && status < 300) return { kind: 'accepted', rejected }; + if (status === 413) return { kind: 'oversized' }; + if (status === 401 || status === 403) { + return body.toLowerCase().includes(DISABLED_ANSWER) + ? { kind: 'disabled' } + : { kind: 'unauthorized' }; + } + if (status === 404) return { kind: 'gone' }; + const named = parseRetryAfter(retryAfter); + if (status === 429) return { kind: 'pause', forMs: named ?? THROTTLE_DEFAULT_MS }; + if (named !== undefined && status >= 500) return { kind: 'pause', forMs: named }; + // ponytail: a `google.rpc.RetryInfo` detail is honoured as "retry", with the local backoff rather + // than its own delay; decode the Status body if Cloud starts relying on the delay. + if ([502, 503, 504].includes(status) || (status >= 500 && body.includes('RetryInfo'))) { + return { kind: 'retry' }; + } + return { kind: 'rejected' }; +} + +/** RFC 9110 §10.2.3: delay-seconds or an HTTP-date. Garbage is ignored, negative means now, and nothing waits past the 24 h age limit. */ +export function parseRetryAfter(value: string | null, now = Date.now()): number | undefined { + if (!value) return undefined; + const text = value.trim(); + const delay = /^-?\d+$/.test(text) ? Number(text) * 1000 : Date.parse(text) - now; + if (!Number.isFinite(delay)) return undefined; + return Math.min(Math.max(delay, 0), DAY_MS); +} + +/** Full jitter: a uniform wait in `[0, backoff]`, the backoff doubling from 1 s to 60 s per consecutive failure. */ +export const backoffMs = (failures: number) => + Math.random() * Math.min(BACKOFF_CAP_MS, 1000 * 2 ** Math.max(0, failures - 1)); + +async function compress(body: Uint8Array): Promise<{ body: Uint8Array; encoding?: string }> { + if (typeof CompressionStream === 'undefined') return { body }; + const stream = new Blob([body as BlobPart]).stream().pipeThrough(new CompressionStream('gzip')); + return { body: new Uint8Array(await new Response(stream).arrayBuffer()), encoding: 'gzip' }; +} + +/** One OTLP request: protobuf, gzipped, lowest HTTP priority, never following a redirect (`Authorization` never crosses an origin). */ +export async function post( + url: string, + encoded: Uint8Array, + token: string | undefined, + signal: AbortSignal, +): Promise<{ status: number; retryAfter: string | null; body: Uint8Array; sent: number }> { + const { body, encoding } = await compress(encoded); + const headers: Record = { + 'Content-Type': 'application/x-protobuf', + Priority: 'u=7', + }; + if (encoding) headers['Content-Encoding'] = encoding; + if (token) headers.Authorization = `Bearer ${token}`; + const response = await fetch(url, { + method: 'POST', + headers, + body: body as BodyInit, + signal, + redirect: 'manual', + keepalive: body.byteLength <= KEEPALIVE_LIMIT, + }); + return { + status: response.status, + retryAfter: response.headers.get('Retry-After'), + body: new Uint8Array(await response.arrayBuffer()), + sent: body.byteLength, + }; +} + +/** + * A refused token is remembered by this fingerprint, never by value (SPEC): two independent + * 32-bit hashes (FNV-1a and the ×31 polynomial) plus the length, so a collision needs all three to + * agree — far beyond what one 32-bit hash gives, and synchronous where `crypto.subtle` is not. + */ +export function fingerprint(text: string): string { + let fnv = 0x811c9dc5; + let poly = 0; + for (let i = 0; i < text.length; i += 1) { + const code = text.charCodeAt(i); + fnv = Math.imul(fnv ^ code, 0x01000193) >>> 0; + poly = (Math.imul(poly, 31) + code) >>> 0; + } + return `${fnv.toString(16)}-${poly.toString(16)}-${text.length}`; +} From 57ced560b2faa1756d50a3f66dac7c2e4389868c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 2/7] feat(telemetry): add Room scopes, spans and paced stats polling One scope per Room owns its session, the lk.connect, lk.reconnect, lk.publish and lk.subscribe spans with their checkpoints and cancelled/failed/reconnect_failed outcomes, join-time subscribe intents, a new connect ending a superseded reconnect, and the Room's custom attributes behind a 64-key limit. Span and window owners are fixed when they open. The poller issues one getStats() per peer connection at the cadence the pipeline sets, bounded per read, isolated per peer, invalidated when a connect is accepted, and re-checks the opt-out before every read and submit. Readings are folded per layer into 60 s windows the way the core does: counters summed across a track's layers, gauges from the window's own readings, windows closed on the pipeline clock, idle layers retired from the same timer. --- src/telemetry/poller.ts | 101 ++++++ src/telemetry/scope.ts | 710 ++++++++++++++++++++++++++++++++++++++++ src/telemetry/webrtc.ts | 184 +++++++++++ 3 files changed, 995 insertions(+) create mode 100644 src/telemetry/poller.ts create mode 100644 src/telemetry/scope.ts create mode 100644 src/telemetry/webrtc.ts diff --git a/src/telemetry/poller.ts b/src/telemetry/poller.ts new file mode 100644 index 0000000000..e65c897ad1 --- /dev/null +++ b/src/telemetry/poller.ts @@ -0,0 +1,101 @@ +/** + * One `getStats()` per peer connection, paced by the scope — never per track, never while opted + * out. A read without an answer in 5 s is skipped; a wake-up only ever moves the next read closer. + */ +import { unref } from './otlp'; +import type { Pipeline } from './pipeline'; +import type { TelemetryScope } from './scope'; +import type { TrackRef } from './webrtc'; + +const READ_TIMEOUT_MS = 5000; + +export interface PeerStatsSource { + /** The Room's publisher and subscriber connections, whichever exist right now. */ + peers(): Array<{ getStats(): Promise | undefined } | undefined>; + /** `MediaStreamTrack` id → the Room's published or subscribed track. */ + tracks(): Map; +} + +export class StatsPoller { + private timer?: ReturnType; + + private deadline = Number.POSITIVE_INFINITY; + + private reading = false; + + private running = false; + + /** Bumped by start and stop: a read that returns after either is not this connection's. */ + private generation = 0; + + constructor( + private scope: TelemetryScope, + private pipeline: Pipeline, + private source: PeerStatsSource, + ) { + scope.onWake = () => this.arm(); + } + + start() { + this.generation += 1; + this.running = true; + this.arm(); + } + + stop() { + this.generation += 1; + this.running = false; + clearTimeout(this.timer); + this.timer = undefined; + this.deadline = Number.POSITIVE_INFINITY; + } + + private arm() { + if (!this.running || this.reading) return; + const delay = this.scope.statsPollIntervalMs(); + const at = Date.now() + delay; + if (at >= this.deadline) return; // an earlier deadline stands + clearTimeout(this.timer); + this.deadline = at; + this.timer = unref(setTimeout(() => this.poll().catch(() => {}), delay)); + } + + private async poll() { + this.timer = undefined; + this.deadline = Number.POSITIVE_INFINITY; + if (!this.running || !this.pipeline.enabled) return; + this.reading = true; + // One poll belongs to one connection: its peers, its track map, its generation. The gate runs + // before every read and after every answer, so neither an old answer nor an old peer's next + // read lands under a later connection, and no `getStats()` follows `disableTelemetry()`. + const { generation } = this; + const { connection } = this.scope; // a connect accepted meanwhile ends this poll too + const current = () => + generation === this.generation && + connection === this.scope.connection && + this.running && + this.pipeline.enabled; + try { + const tracks = this.source.tracks(); + for (const peer of this.source.peers()) { + if (!current()) break; + let report: RTCStatsReport | undefined; + try { + const pending = peer?.getStats(); + if (!pending) continue; + report = await Promise.race([ + pending, + new Promise((resolve) => unref(setTimeout(resolve, READ_TIMEOUT_MS))), + ]); + } catch { + continue; // one connection's failing read never costs the other its reading + } + if (!current()) break; + if (report) this.scope.recordPeerStats(report, tracks); + } + } finally { + this.reading = false; + this.arm(); + } + } +} diff --git a/src/telemetry/scope.ts b/src/telemetry/scope.ts new file mode 100644 index 0000000000..86e3aba4e8 --- /dev/null +++ b/src/telemetry/scope.ts @@ -0,0 +1,710 @@ +/** + * One scope per Room: its trace id and attributes, its spans, its RTC windows and the two app + * calls. A scope is never ended — a Room's last record is simply its last (SPEC). + */ +import { DisconnectReason, ReconnectReason } from '@livekit/protocol'; +import log from '../logger'; +import { + type Attributes, + type LogRecord, + type SeverityName, + SpanKind, + type SpanRecord, + mask, + randomHex, + unref, +} from './otlp'; +import type { Pipeline } from './pipeline'; +import { + type Layers, + type Sample, + StatsWindow, + type TrackRef, + foldLayers, + peerSamples, +} from './webrtc'; + +export type Outcome = 'ok' | 'error' | 'cancelled'; + +export interface RoomIdentity { + sid?: string; + name?: string; + participantSid?: string; + participantIdentity?: string; +} + +export interface SpanTrack { + sid: string; + kind: 'audio' | 'video'; + source?: string; + remoteIdentity?: string; +} + +const SUBSCRIBE_TIMEOUT_MS = 30_000; +/** A layer with no reading for this long is retired, so the per-track state follows what is active. */ +const LAYER_IDLE_MS = 180_000; +/** A published track is polled every second for its first reading, for this long at most (the core's bound). */ +const UNREAD_TIMEOUT_MS = 30_000; +const CPU_LIMITED_MS = 60_000; +const MAX_KEY_BYTES = 128; +const MAX_VALUE_BYTES = 1024; +const MAX_ATTRIBUTES = 64; + +const utf8 = (text: string) => new TextEncoder().encode(text).length; +const validValue = (value: unknown) => typeof value === 'string' && utf8(value) <= MAX_VALUE_BYTES; + +/** `error.type`: a type name, never a message (SPEC). */ +export const errorType = (error: unknown) => (error instanceof Error && error.name) || 'unknown'; + +/** A telemetry failure is reported at debug level — and a throwing log extension is swallowed too. */ +export function diagnose(context: object) { + try { + log.debug('telemetry: dropped a failing call', context); + } catch { + // never into the SDK + } +} + +/** Scheduled work runs inside the guard too: a timer callback never throws into the host. */ +export const scheduled = (run: () => void) => () => { + try { + run(); + } catch (error) { + diagnose({ error }); + } +}; + +/** Every method of a guarded object swallows its own failure: telemetry never throws into SDK or app code. */ +export function guarded(target: T): T { + return new Proxy(target, { + get(t, prop) { + const value = Reflect.get(t, prop, t); + if (typeof value !== 'function') return value; + return (...args: unknown[]) => { + try { + return value.apply(t, args); + } catch (error) { + diagnose({ method: String(prop), error }); + return undefined; + } + }; + }, + }); +} + +/** A protocol enum value → SPEC's lowercase name (`RR_SIGNAL_DISCONNECTED` → `signal_disconnected`). */ +const enumName = (table: Record, value: number, strip: RegExp) => + (table[value] ?? table[0]).replace(strip, '').toLowerCase(); +export const reconnectReasonName = (reason = ReconnectReason.RR_UNKNOWN) => + enumName(ReconnectReason, reason, /^RR_/); +export const disconnectReasonName = (reason = DisconnectReason.UNKNOWN_REASON) => + enumName(DisconnectReason, reason, /_REASON$/); + +/** Who a record belongs to, fixed when a span or window opens: the project and the Room's identity of that connection. */ +export interface Owner { + host?: string; + /** The capture-time decision: `true` a Cloud project, `false` a self-hosted server (never sent), `undefined` no server yet. */ + collects?: boolean; + connection: number; + attributes: Attributes; +} + +export class TelemetrySpan { + readonly spanId = randomHex(8); + + private readonly startMs = Date.now(); + + private events: SpanRecord['events'] = []; + + private attributes: Attributes; + + ended = false; + + constructor( + private scope: TelemetryScope, + readonly name: string, + private kind: number, + attributes: Attributes, + readonly owner: Owner, + private parentSpanId?: string, + ) { + this.attributes = { ...attributes }; + } + + private get admits() { + return !this.ended && this.scope.admits(); + } + + step(name: string) { + if (this.admits) this.events.push({ name, timeMs: Date.now() }); + } + + has(step: string): boolean { + return this.events.some((event) => event.name === step); + } + + setAttribute(key: string, value: Attributes[string]) { + if (this.admits) this.attributes[key] = value; + } + + /** Ending twice is a no-op, as on every other platform. */ + end(outcome: Outcome = 'ok', error?: string, message?: string) { + if (this.ended) return; + this.ended = true; + this.scope.finish(this, { + kind: 'span', + name: this.name, + spanKind: this.kind, + traceId: this.scope.traceId, + spanId: this.spanId, + parentSpanId: this.parentSpanId, + startMs: this.startMs, + endMs: Date.now(), + // Cancellation is `Unset` like success: only a failure is an error (SPEC). + status: outcome === 'error' ? 2 : 0, + statusMessage: message, + attributes: { ...this.attributes, 'lk.outcome': outcome, 'error.type': error }, + events: this.events, + }); + } + + fail(error: unknown) { + const message = error instanceof Error ? error.message : String(error); + this.end('error', mask(errorType(error)), mask(message)); + } + + /** @internal The opt-out: closed without a record, every buffer emptied. */ + purge() { + this.ended = true; + this.events = []; + this.attributes = {}; + this.owner.attributes = {}; + } +} + +function endWith(span: TelemetrySpan | undefined, outcome: Outcome, error?: unknown) { + if (!span) return; + if (outcome !== 'error') span.end(outcome); + else if (typeof error === 'string') span.end('error', error); + else span.fail(error); +} + +export class TelemetryScope { + readonly traceId = randomHex(16); + + /** The project this Room is routed to; `undefined` before connect, on a non-Cloud host, or under the collector override. */ + host?: string; + + /** `false` once a server is known that has no ingest: this Room's records are dropped at the door (SPEC). */ + collects?: boolean; + + /** Has a server and has not disconnected: the pipeline meters uploads while any Room is in a call. */ + inCall = false; + + /** A subscribe intent wants the next `getStats()` within a second; the Room's poller listens here. */ + onWake?: () => void; + + private serverUrl?: string; + + identity: RoomIdentity = {}; + + /** Prototype-free, so `constructor` or `__proto__` are keys like any other (the core's rule). */ + private custom: Record = Object.create(null); + + private connectSpan?: TelemetrySpan; + + private reconnectSpan?: TelemetrySpan; + + private reconnectAttempts = 0; + + private pending = new Map< + string, + { span: TelemetrySpan; deadline: number; timer: ReturnType } + >(); + + private windows = new Map(); + + /** Closes windows at their 60 s boundary on the pipeline's clock, whether or not another reading comes. */ + private windowTimer?: ReturnType; + + /** Every layer's last totals per track and direction, so a layer that stops reporting keeps counting (the core's rule); retired when idle. */ + private layers = new Map>(); + + private lastCpuMs = new Map(); + + /** Published tracks without a reading yet → when to stop waiting: polled every second like a pending subscribe. */ + private unread = new Map(); + + /** An encoder was CPU-limited within the last minute: the cadence stretches ×2 (SPEC). */ + cpuLimitedUntil = 0; + + /** Bumped by every user connect: a span or window opened under an earlier connection keeps that owner. */ + connection = 0; + + private open = new Set(); + + constructor(private pipeline: Pipeline) { + pipeline.track(this); // weakly: a Room nobody uses is not retained by telemetry + } + + /** Nothing is captured after the opt-out. */ + admits(): boolean { + return this.pipeline.enabled; + } + + private owner(): Owner { + return { + host: this.host, + collects: this.collects, + connection: this.connection, + attributes: this.attributes(), + }; + } + + /** The Room's identity is late-known (sid at join), so the current connection reads it live; an earlier one keeps its snapshot. */ + private ownerAttributes(owner: Owner): Attributes { + return owner.connection === this.connection ? this.attributes() : owner.attributes; + } + + attributes(): Attributes { + return { + 'session.id': this.traceId, + 'lk.room.sid': this.identity.sid, + 'lk.room.name': this.identity.name, + 'lk.participant.sid': this.identity.participantSid, + 'lk.participant.identity': this.identity.participantIdentity, + ...this.custom, + }; + } + + /** The server URL and token the Room connects with — at connect, and again on every refresh and move (SPEC). */ + setServer(serverUrl: string, token: string) { + if (!this.admits()) return; // no destination or credential is retained after the opt-out + this.serverUrl = serverUrl; + this.host = this.pipeline.setServer(serverUrl, token, this); + this.collects = this.host !== undefined; + this.inCall = true; + this.pipeline.activate(this); + // A span or window opened before this Room had any server takes its first one (SPEC), however + // late it finishes — Cloud project or self-hosted alike; one opened under a server keeps that. + const adopt = (owner: Owner) => { + if (owner.collects !== undefined) return; + owner.host = this.host; + owner.collects = this.collects; + }; + this.open.forEach((span) => adopt(span.owner)); + this.windows.forEach(({ owner }) => adopt(owner)); + } + + refreshToken(token: string) { + if (this.serverUrl) this.setServer(this.serverUrl, token); + } + + setRoom(identity: RoomIdentity, replace = false) { + if (!this.admits()) return; + this.identity = replace ? { ...identity } : { ...this.identity, ...identity }; + } + + private validKey(key: string) { + return ( + key.length > 0 && utf8(key) <= MAX_KEY_BYTES && !key.startsWith('lk.') && key !== 'session.id' + ); + } + + /** `custom.` under this Room; over the limits → rejected and counted, never truncated (SPEC). */ + emitCustom(name: string, attributes: Record = {}) { + const entries = Object.entries(attributes); + const valid = + name.length > 0 && + utf8(name) <= MAX_KEY_BYTES && + entries.length <= MAX_ATTRIBUTES && + entries.every(([key, value]) => this.validKey(key) && validValue(value)); + if (valid) this.emit(`custom.${name}`, attributes); + else this.pipeline.count('dropped.invalid'); + } + + /** A correlation attribute for this Room's later records; `null` removes it. */ + setAttribute(key: string, value: string | null | undefined) { + if (!this.admits()) return; + const room = key in this.custom || Object.keys(this.custom).length < MAX_ATTRIBUTES; // own keys only: no prototype + if (!this.validKey(key) || (value != null && !(validValue(value) && room))) { + this.pipeline.count('dropped.invalid'); + return; + } + this.closeWindows(); // a window never mixes readings taken under two values (SPEC) + if (value != null) this.custom[key] = value; + else delete this.custom[key]; + } + + /** `hold`: the span owns the uplink while open (`lk.connect`, `lk.reconnect`), a soft hold on uploads. */ + start( + name: string, + options: { + kind?: number; + attributes?: Attributes; + parent?: TelemetrySpan; + hold?: boolean; + } = {}, + ): TelemetrySpan { + const parent = options.parent && !options.parent.ended ? options.parent : undefined; + const span = new TelemetrySpan( + this, + name, + options.kind ?? SpanKind.internal, + options.attributes ?? {}, + this.owner(), + parent?.spanId, + ); + if (!this.admits()) { + span.ended = true; // after the opt-out a span is handed out ended: no hold, no record + return guarded(span); + } + this.open.add(span); + if (options.hold) this.pipeline.hold(span, true); + return guarded(span); + } + + /** @internal */ + finish(span: TelemetrySpan, record: SpanRecord) { + this.pipeline.hold(span, false); + this.open.delete(span); + if (!this.admits()) return; + record.host = span.owner.host; + record.attributes = { ...this.ownerAttributes(span.owner), ...record.attributes }; + this.pipeline.record(record, this, false, span.owner); + } + + /** `owner`: the connection a window was opened under; a record of the moment otherwise. */ + emit( + eventName: string, + attributes: Attributes = {}, + severity: SeverityName = 'info', + owner: Owner = this.owner(), + ) { + const record: LogRecord = { + kind: 'log', + timeMs: Date.now(), + severity, + eventName, + // Log viewers key their line on the body, and not every backend surfaces event_name yet. + body: eventName, + attributes: { ...this.ownerAttributes(owner), 'otel.event.name': eventName, ...attributes }, + traceId: this.traceId, + host: owner.host, + }; + this.pipeline.record(record, this, eventName === 'lk.rtc.stats.sample', owner); + } + + /** The open connect or reconnect span: what a publish nests under. */ + uplink(): TelemetrySpan | undefined { + return [this.connectSpan, this.reconnectSpan].find((span) => span && !span.ended); + } + + /** Where a warning belongs: the newest open publish, else the open connect or reconnect. */ + ambient(): TelemetrySpan | undefined { + const publish = Array.from(this.open) + .reverse() + .find((span) => span.name === 'lk.publish' && !span.ended); + return publish ?? this.uplink(); + } + + /** An SDK warning or error line filed under this Room (and its open span, when any). */ + log(severity: 'warn' | 'error', body: string, logger: string) { + this.pipeline.record( + { + kind: 'log', + timeMs: Date.now(), + severity, + body, + attributes: { ...this.attributes(), 'lk.log.source': 'sdk', 'lk.log.logger': logger }, + traceId: this.traceId, + spanId: this.ambient()?.spanId, + host: this.host, + }, + this, + false, + this.owner(), + ); + } + + /** A user-initiated connect: a fresh identity, the destination, one `lk.connect` span that holds uploads. */ + connectStarted(url: string, token: string) { + // Whatever the previous connection still had open ships under that connection's owner; a poll + // in flight is dropped (the poller compares `connection`). + this.closeWindows(); + this.layers.clear(); + this.unread.clear(); + this.lastCpuMs.clear(); + this.connection += 1; + this.setRoom({}, true); + this.setServer(url, token); + this.connectSpan?.end('cancelled'); + this.reconnectSpan?.end('cancelled'); // a new connection supersedes a reconnect in progress + this.reconnectSpan = undefined; + this.connectSpan = this.start('lk.connect', { + kind: SpanKind.client, + attributes: { 'lk.connect.attempt': 1 }, + hold: true, + }); + } + + /** + * The required checkpoints keep SPEC's order: a peer connection created before the join response + * (offer-with-join) is the optional `early_pc_created`, and `pc_created` is stamped when the join + * is adopted, as Swift does. + */ + connectStep(name: string) { + const span = this.connectSpan; + if (!span) return; + if (name === 'pc_created' && !span.has('join_recv')) { + span.step('early_pc_created'); + return; + } + span.step(name); + if (name === 'join_recv' && span.has('early_pc_created')) span.step('pc_created'); + } + + /** `error` is the thrown value, or a reason name to report as `error.type` (`signal_close`, `reconnect_failed`). */ + connectEnded(outcome: Outcome, error?: unknown) { + endWith(this.connectSpan, outcome, error); + this.connectSpan = undefined; + } + + /** One `lk.reconnect` span per reconnect cycle; a resume that turns into a restart is the same cycle, one attempt later. */ + reconnectAttempt(mode: 'quick' | 'full', reason?: ReconnectReason) { + if (!this.reconnectSpan || this.reconnectSpan.ended) { + this.reconnectAttempts = 0; + this.reconnectSpan = this.start('lk.reconnect', { + kind: SpanKind.client, + attributes: { 'lk.reconnect.reason': reconnectReasonName(reason) }, + hold: true, + }); + } + this.reconnectAttempts += 1; + this.reconnectSpan.setAttribute('lk.reconnect.mode', mode); + this.reconnectSpan.setAttribute('lk.reconnect.attempts', this.reconnectAttempts); + this.reconnectSpan.step(`attempt ${this.reconnectAttempts} ${mode}`); + } + + get reconnecting(): boolean { + return this.reconnectSpan !== undefined && !this.reconnectSpan.ended; + } + + reconnectEnded(outcome: Outcome, error?: unknown) { + endWith(this.reconnectSpan, outcome, error); + this.reconnectSpan = undefined; + } + + /** The intent to subscribe exists: autoSubscribe at publish or join, or a manual subscribe (SPEC: the core owns `lk.subscribe`). */ + subscribeStarted(track: SpanTrack) { + if (!this.admits() || this.pending.has(track.sid)) return; + const span = this.start('lk.subscribe', { + attributes: { + 'lk.track.sid': track.sid, + 'lk.track.kind': track.kind, + 'lk.track.source': track.source, + 'lk.participant.remote_identity': track.remoteIdentity, + }, + }); + const end = scheduled(() => this.endSubscribe(track.sid, 'error', 'timed_out')); + this.pending.set(track.sid, { + span, + deadline: Date.now() + SUBSCRIBE_TIMEOUT_MS, + timer: unref(setTimeout(end, SUBSCRIBE_TIMEOUT_MS)), + }); + this.onWake?.(); + } + + subscribed(track: SpanTrack) { + this.subscribeStarted(track); + this.pending.get(track.sid)?.span.step('subscribed'); + } + + subscribeFailed(sid: string, error: string) { + this.endSubscribe(sid, 'error', error); + } + + trackEnded(sid: string) { + const pending = this.pending.get(sid); + if (pending) { + const timedOut = Date.now() >= pending.deadline; + this.endSubscribe(sid, timedOut ? 'error' : 'cancelled', timedOut ? 'timed_out' : undefined); + } + for (const key of this.windows.keys()) { + if (key.startsWith(`${sid}:`)) this.closeWindow(key); + } + this.lastCpuMs.delete(sid); + this.unread.delete(sid); + this.layers.delete(`${sid}:inbound`); + this.layers.delete(`${sid}:outbound`); + } + + private endSubscribe(sid: string, outcome: Outcome, error?: string) { + const pending = this.pending.get(sid); + if (!pending) return; + clearTimeout(pending.timer); + this.pending.delete(sid); + pending.span.end(outcome, error); + } + + /** When the Room should poll `getStats()` next: every second while a subscribe awaits first media, else twice per window. */ + statsPollIntervalMs(): number { + for (const [sid, until] of Array.from(this.unread)) + if (until <= Date.now()) this.unread.delete(sid); + return this.pending.size > 0 || this.unread.size > 0 ? 1000 : this.pipeline.statsWindowMs / 2; + } + + /** A local track was published: its first reading is wanted soon. */ + trackPublished(sid: string) { + if (!this.admits()) return; + this.unread.set(sid, Date.now() + UNREAD_TIMEOUT_MS); + this.onWake?.(); + } + + recordPeerStats(report: RTCStatsReport, tracks: Map) { + if (!this.pipeline.enabled) return; + const now = Date.now(); + for (const { ref, layers } of peerSamples(report, tracks).values()) { + const key = `${ref.sid}:${ref.direction}`; + const known = this.layers.get(key) ?? new Map(); + for (const [layer, reading] of layers) known.set(layer, { reading, at: now }); + this.layers.set(key, known); + const totals: Layers = new Map(Array.from(known, ([layer, { reading }]) => [layer, reading])); + const sample = foldLayers(totals, layers.keys()); + let entry = this.windows.get(key); + if (!entry) { + entry = { ref, window: new StatsWindow(), owner: this.owner() }; + this.windows.set(key, entry); + this.armWindows(); + } + entry.window.add(sample); + this.unread.delete(ref.sid); + if (ref.direction === 'inbound' && (sample.counters['lk.rtc.bytes'] ?? 0) > 0) { + const pending = this.pending.get(ref.sid); + if (pending) { + pending.span.step('first_media'); + this.endSubscribe(ref.sid, 'ok'); + } + } + const cpuMs = sample.counters['lk.rtc.quality_limitation.cpu_ms']; + if (cpuMs !== undefined) { + const last = this.lastCpuMs.get(ref.sid); + if (last !== undefined && cpuMs > last) { + this.cpuLimitedUntil = now + CPU_LIMITED_MS; + this.pipeline.applyCadence(); // the stretch applies now; the pipeline times the relief + } + this.lastCpuMs.set(ref.sid, cpuMs); + } + } + } + + private armWindows() { + clearTimeout(this.windowTimer); + this.windowTimer = undefined; + let due = Number.POSITIVE_INFINITY; + for (const { window } of this.windows.values()) { + due = Math.min(due, window.started + this.pipeline.statsWindowMs); + } + for (const known of this.layers.values()) { + for (const { at } of known.values()) due = Math.min(due, at + LAYER_IDLE_MS); + } + if (due === Number.POSITIVE_INFINITY) return; + const wait = Math.max(0, due - Date.now()); + this.windowTimer = unref( + setTimeout( + scheduled(() => this.closeDue()), + wait, + ), + ); + } + + /** @internal The cadence factor changed: the windows' boundaries and the next poll move with it. */ + cadenceChanged() { + this.armWindows(); + this.onWake?.(); + } + + /** Windows past their boundary ship; layer histories idle for 3 min retire — on the timer, no reading needed. */ + private closeDue() { + const now = Date.now(); + for (const [key, { window }] of Array.from(this.windows)) { + if (now - window.started >= this.pipeline.statsWindowMs) this.closeWindow(key); + } + for (const [key, known] of Array.from(this.layers)) { + for (const [layer, { at }] of Array.from(known)) { + if (now - at >= LAYER_IDLE_MS) known.delete(layer); + } + if (known.size === 0) this.layers.delete(key); + } + this.armWindows(); + } + + closeWindows() { + for (const key of Array.from(this.windows.keys())) this.closeWindow(key); + this.armWindows(); // nothing left: the timer goes + } + + private closeWindow(key: string) { + const entry = this.windows.get(key); + if (!entry) return; + this.windows.delete(key); + if (entry.window.samples === 0) return; + this.emit( + 'lk.rtc.stats.sample', + { + 'lk.track.sid': entry.ref.sid, + 'lk.track.kind': entry.ref.kind, + 'lk.track.direction': entry.ref.direction, + ...entry.window.attributes(), + }, + 'info', + entry.owner, + ); + } + + /** The Room left connected for good — never on a reconnect. */ + disconnected(reason?: DisconnectReason, override?: string) { + const name = override ?? disconnectReasonName(reason); + for (const sid of Array.from(this.pending.keys())) this.trackEnded(sid); + this.closeWindows(); + this.unread.clear(); + this.layers.clear(); + this.lastCpuMs.clear(); + this.cpuLimitedUntil = 0; + this.armWindows(); // nothing left to time: the idle timer goes too + this.emit( + 'lk.room.disconnected', + { 'lk.disconnect.reason': name }, + name === 'client_initiated' ? 'info' : 'warn', + ); + this.inCall = false; + this.pipeline.forget(this); + this.pipeline.flush().catch(() => {}); + } + + /** The opt-out: every timer stopped, every open span closed and emptied, no identity, destination or attribute retained. */ + purge() { + for (const pending of this.pending.values()) clearTimeout(pending.timer); + this.pending.clear(); + clearTimeout(this.windowTimer); + this.windowTimer = undefined; + this.cpuLimitedUntil = 0; + this.windows.clear(); + this.layers.clear(); + this.unread.clear(); + this.lastCpuMs.clear(); + this.custom = Object.create(null); + this.identity = {}; + this.serverUrl = undefined; + this.host = undefined; + this.collects = undefined; + this.inCall = false; + for (const span of this.open) { + span.purge(); + this.pipeline.hold(span, false); + } + this.open.clear(); + this.connectSpan = undefined; + this.reconnectSpan = undefined; + } +} diff --git a/src/telemetry/webrtc.ts b/src/telemetry/webrtc.ts new file mode 100644 index 0000000000..e1a65c2c57 --- /dev/null +++ b/src/telemetry/webrtc.ts @@ -0,0 +1,184 @@ +/** + * One `getStats()` report → one reading per track in SPEC keys and units (ms), and the window that + * folds readings into one `lk.rtc.stats.sample`: counters as the last reading, gauges as min/max/avg. + */ +import type { Attributes } from './otlp'; + +export interface TrackRef { + sid: string; + kind: 'audio' | 'video'; + direction: 'inbound' | 'outbound'; +} + +export interface Sample { + codec?: string; + counters: Record; + gauges: Record; +} + +type Stat = Record; + +/** Gauges keep their precision; durations are integer counters. */ +const ms = (seconds: number | undefined) => (seconds === undefined ? undefined : seconds * 1000); +const msInt = (seconds: number | undefined) => + seconds === undefined ? undefined : Math.round(seconds * 1000); + +/** One track's layers (simulcast: by rid, else ssrc, else the stat id — SPEC `RtcStatsSample.layer`), each a reading. */ +export type Layers = Map; + +/** The report's RTP streams, each resolved to a published or subscribed track by its `MediaStreamTrack` id. */ +export function peerSamples( + report: RTCStatsReport, + tracks: Map, +): Map { + const stats = new Map(); + report.forEach((stat: Stat) => stats.set(stat.id, stat)); + const all = Array.from(stats.values()); + // The transport's selected pair, else the nominated succeeded one (not every browser names it). + const selectedId = all.find( + (s) => s.type === 'transport' && s.selectedCandidatePairId, + )?.selectedCandidatePairId; + const pair = + (selectedId && stats.get(selectedId)) ?? + all.find( + (s) => + s.type === 'candidate-pair' && (s.selected || (s.nominated && s.state === 'succeeded')), + ); + const pairRtt = ms(pair?.currentRoundTripTime); + const out = new Map(); + for (const stat of all) { + const outbound = stat.type === 'outbound-rtp'; + if (!outbound && stat.type !== 'inbound-rtp') continue; + const trackId = outbound + ? (stats.get(stat.mediaSourceId)?.trackIdentifier ?? stat.trackIdentifier) + : stat.trackIdentifier; + const ref = tracks.get(trackId); + if (!ref || (ref.direction === 'outbound') !== outbound) continue; + let entry = out.get(ref.sid); + if (!entry) { + entry = { ref, layers: new Map() }; + out.set(ref.sid, entry); + } + const counters: Record = {}; + const gauges: Record = {}; + const set = (target: Record, key: string, value: number | undefined) => { + if (value !== undefined && Number.isFinite(value)) target[key] = value; + }; + if (outbound) { + set(counters, 'lk.rtc.bytes', stat.bytesSent); + set(counters, 'lk.rtc.packets', stat.packetsSent); + set(gauges, 'lk.rtc.fps', stat.framesPerSecond); + // The remote-inbound stream the stat names, else the one naming the stat (`localId`). + const remote = + stats.get(stat.remoteId) ?? + all.find((s) => s.type === 'remote-inbound-rtp' && s.localId === stat.id); + set(gauges, 'lk.rtc.rtt_ms', ms(remote?.roundTripTime)); + const limits = stat.qualityLimitationDurations; + if (limits) { + set(counters, 'lk.rtc.quality_limitation.bandwidth_ms', msInt(limits.bandwidth)); + set(counters, 'lk.rtc.quality_limitation.cpu_ms', msInt(limits.cpu)); + set(counters, 'lk.rtc.quality_limitation.other_ms', msInt(limits.other)); + } + } else { + set(counters, 'lk.rtc.bytes', stat.bytesReceived); + set(counters, 'lk.rtc.packets', stat.packetsReceived); + set(counters, 'lk.rtc.packets_lost', stat.packetsLost); + set(counters, 'lk.rtc.freeze_count', stat.freezeCount); + set(counters, 'lk.rtc.freezes_duration_ms', msInt(stat.totalFreezesDuration)); + set(counters, 'lk.rtc.pause_count', stat.pauseCount); + set(counters, 'lk.rtc.pauses_duration_ms', msInt(stat.totalPausesDuration)); + set(counters, 'lk.rtc.concealed_samples', stat.concealedSamples); + set(counters, 'lk.rtc.concealment_events', stat.concealmentEvents); + set(counters, 'lk.rtc.silent_concealed_samples', stat.silentConcealedSamples); + set(counters, 'lk.rtc.interruption_count', stat.interruptionCount); + set(counters, 'lk.rtc.interruptions_duration_ms', msInt(stat.totalInterruptionDuration)); + set(counters, 'lk.rtc.jitter_buffer_delay_ms', msInt(stat.jitterBufferDelay)); + set(counters, 'lk.rtc.jitter_buffer_emitted_count', stat.jitterBufferEmittedCount); + set(gauges, 'lk.rtc.jitter_ms', ms(stat.jitter)); + set(gauges, 'lk.rtc.fps', stat.framesPerSecond); + set(gauges, 'lk.rtc.audio_level', stat.audioLevel); + set(gauges, 'lk.rtc.rtt_ms', pairRtt); + } + const codec = stats.get(stat.codecId)?.mimeType; + entry.layers.set(String(stat.rid ?? stat.ssrc ?? stat.id), { codec, counters, gauges }); + } + return out; +} + +/** + * One track's layers folded into one reading, as the core does: cumulative counters summed across + * every layer ever seen (quality-limitation durations are per encoder: the maximum), gauges and + * codec only from the layers in this reading (`fresh`), the maximum across them. + */ +export function foldLayers(layers: Layers, fresh: Iterable = layers.keys()): Sample { + const sample: Sample = { counters: {}, gauges: {} }; + for (const layer of layers.values()) { + for (const [key, value] of Object.entries(layer.counters)) { + const current = sample.counters[key]; + sample.counters[key] = key.startsWith('lk.rtc.quality_limitation.') + ? Math.max(current ?? -Infinity, value) + : (current ?? 0) + value; + } + } + for (const id of fresh) { + const layer = layers.get(id); + if (!layer) continue; + sample.codec ??= layer.codec; + for (const [key, value] of Object.entries(layer.gauges)) { + sample.gauges[key] = Math.max(sample.gauges[key] ?? -Infinity, value); + } + } + return sample; +} + +interface Gauge { + min: number; + max: number; + sum: number; + count: number; +} + +export class StatsWindow { + readonly started = Date.now(); + + samples = 0; + + codec?: string; + + private counters: Record = {}; + + private gauges = new Map(); + + add(sample: Sample) { + this.samples += 1; + this.codec = sample.codec ?? this.codec; + Object.assign(this.counters, sample.counters); + for (const [key, value] of Object.entries(sample.gauges)) { + if (!Number.isFinite(value)) continue; + const gauge = this.gauges.get(key); + if (!gauge) { + this.gauges.set(key, { min: value, max: value, sum: value, count: 1 }); + } else { + gauge.min = Math.min(gauge.min, value); + gauge.max = Math.max(gauge.max, value); + gauge.sum += value; + gauge.count += 1; + } + } + } + + attributes(): Attributes { + const attributes: Attributes = { + 'lk.rtc.window_ms': Date.now() - this.started, + 'lk.rtc.samples': this.samples, + 'lk.rtc.codec': this.codec, + ...this.counters, + }; + for (const [key, gauge] of this.gauges) { + attributes[`${key}.min`] = gauge.min; + attributes[`${key}.max`] = gauge.max; + attributes[`${key}.avg`] = gauge.sum / gauge.count; + } + return attributes; + } +} From a01895c6e55ccd3df9cb052f75545d1afe731d01 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 3/7] feat(telemetry): capture device state and SDK warnings The browser answers two device signals, page visibility and network information where Chromium exposes it; everything else arrives through the host seam. Any logger obtained through getLogger forwards warn and error records to the pipeline before the console level filters them, with every argument passed through unchanged; the forwarder survives setLevel, resetLevel and rebuild, and a log context carries its Room's scope through a weak reference so a line is attributed by identity, never by name. --- src/logger.ts | 78 ++++++++++++++++++++++ src/telemetry/device.ts | 139 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 217 insertions(+) create mode 100644 src/telemetry/device.ts diff --git a/src/logger.ts b/src/logger.ts index a472d65af4..fde68ccfe2 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -49,6 +49,80 @@ livekitLogger.setDefaultLevel(LogLevel.info); export default livekitLogger as StructuredLogger; +/** + * @internal Receives every warn/error line of the SDK's loggers whatever their console level + * (telemetry). The console gets what it got before; the devtools call site becomes the forwarder. + */ +export type LogCapture = ( + level: LogLevel, + msg: unknown, + context?: object, + loggerName?: string, +) => void; + +let logCapture: LogCapture | undefined; + +/** + * @internal The object a line is about (a Room's telemetry scope), carried through the structured + * context without being enumerable: the console and log extensions see the context as before. + */ +export const LOG_OWNER: unique symbol = Symbol('livekit.logOwner'); + +/** @internal */ +export function setLogCapture(capture?: LogCapture) { + logCapture = capture; +} + +const captured = new WeakSet(); + +type CapturedMethod = ((...args: unknown[]) => void) & { lkForwards?: boolean }; + +function forwarder(logger: log.Logger, method: 'warn' | 'error'): CapturedMethod { + const real = logger[method] as CapturedMethod; + if (real.lkForwards) return real; + const name = (logger as { name?: string }).name; + const forward: CapturedMethod = (...args) => { + try { + const context = typeof args[1] === 'object' && args[1] !== null ? args[1] : undefined; + // Whatever path a context took here, the console never lists the owner. + if (context && Object.getOwnPropertyDescriptor(context, LOG_OWNER)?.enumerable) { + Object.defineProperty(context, LOG_OWNER, { enumerable: false }); + } + logCapture?.(LogLevel[method], args[0], context, name); + } catch { + // telemetry never breaks logging + } + real(...args); // the original call, argument for argument + }; + forward.lkForwards = true; + return forward; +} + +// loglevel assigns `warn`/`error` anew on every `setLevel` (a noop below the level), so the +// forwarder is re-applied after each `setLevel` and runs before whatever loglevel assigned. +function captureWarnings(logger: log.Logger) { + if (captured.has(logger)) return; + captured.add(logger); + const wrap = () => { + logger.warn = forwarder(logger, 'warn'); + logger.error = forwarder(logger, 'error'); + }; + // `setLevel`, `resetLevel` and `rebuild` all reassign the methods. + const target = logger as unknown as Record unknown>; + for (const name of ['setLevel', 'resetLevel', 'rebuild']) { + const original = target[name]; + if (typeof original !== 'function') continue; + target[name] = (...args: unknown[]) => { + const result = original.apply(logger, args); + wrap(); + return result; + }; + } + wrap(); +} + +livekitLoggers.forEach(captureWarnings); + /** * @internal * @@ -64,6 +138,7 @@ export default livekitLogger as StructuredLogger; export function getLogger(name: string, ctxFn?: ContextProvider) { const logger = log.getLogger(name); logger.setDefaultLevel(livekitLogger.getLevel()); + captureWarnings(logger); if (!ctxFn) { return logger as StructuredLogger; } @@ -78,6 +153,9 @@ function wrapWithContext(base: StructuredLogger, ctxFn: ContextProvider): Struct const wrap = (method: LogMethod) => (msg: string, extra?: object) => { const ctx = ctxFn(); const merged = ctx || extra ? { ...ctx, ...extra } : undefined; + const owner = (ctx as Record | undefined)?.[LOG_OWNER]; + if (merged && owner) + Object.defineProperty(merged, LOG_OWNER, { value: owner, enumerable: false }); base[method](msg, merged); }; diff --git a/src/telemetry/device.ts b/src/telemetry/device.ts new file mode 100644 index 0000000000..192fc65363 --- /dev/null +++ b/src/telemetry/device.ts @@ -0,0 +1,139 @@ +/** + * Device state and the `lk.device.*` events, cadence factor and holds it drives (SPEC). The pipeline + * measures nothing itself: a page says whether it is visible and (on Chromium) what it is connected + * through; React Native reports the rest through the host hook. + */ +import type { Attributes } from './otlp'; + +export type NetworkType = + 'wifi' | 'cell' | 'wired' | 'vpn' | 'bluetooth' | 'other' | 'unavailable' | 'unknown'; + +/** @internal What a host reports about the device; every field optional, reported on change. */ +export interface DeviceState { + appState?: 'foreground' | 'background'; + networkType?: NetworkType; + /** Cellular or a hotspot; Low Data Mode, Data Saver, `navigator.connection.saveData`. */ + networkExpensive?: boolean; + networkConstrained?: boolean; + thermal?: 'nominal' | 'fair' | 'serious' | 'critical'; + lowPower?: boolean; + memory?: 'normal' | 'warning' | 'critical'; + batteryCharge?: number; + batteryState?: 'charging' | 'discharging'; +} + +const unplugged = (s: DeviceState) => + s.batteryState === 'discharging' && s.batteryCharge !== undefined; + +/** SPEC's cadence table; factors multiply, capped at 4×. */ +export function cadenceFactor(s: DeviceState): number { + let factor = 1; + if (s.appState === 'background') factor *= 2; + if (s.networkConstrained) factor *= 2; + if (s.lowPower) factor *= 2; + factor *= { serious: 2, critical: 4 }[s.thermal as string] ?? 1; + factor *= { warning: 2, critical: 4 }[s.memory as string] ?? 1; + if (unplugged(s) && s.batteryCharge! <= 0.2) factor *= 2; + return Math.min(factor, 4); +} + +/** The soft holds a device raises: Low Data Mode / Data Saver, battery at 10 % unplugged. */ +export const softHold = (s: DeviceState) => + s.networkConstrained === true || (unplugged(s) && s.batteryCharge! <= 0.1); + +/** What changed since the last state, as the records SPEC names — one per group, on change only. */ +export function changes(prev: DeviceState, next: DeviceState): Array<[string, Attributes]> { + const out: Array<[string, Attributes]> = []; + const changed = (...keys: Array) => + keys.some((k) => next[k] !== undefined && next[k] !== prev[k]); + if (changed('appState')) { + out.push(['lk.device.app_state.changed', { 'lk.device.app_state': next.appState }]); + } + if (changed('networkType', 'networkExpensive', 'networkConstrained')) { + out.push([ + 'lk.device.network.changed', + { + 'network.connection.type': next.networkType, + 'lk.device.network.expensive': next.networkExpensive, + 'lk.device.network.constrained': next.networkConstrained, + }, + ]); + } + if (changed('thermal')) { + out.push(['lk.device.thermal.changed', { 'lk.device.thermal.state': next.thermal }]); + } + if (changed('lowPower')) { + out.push(['lk.device.low_power.changed', { 'lk.device.low_power.enabled': next.lowPower }]); + } + if (changed('memory')) { + out.push(['lk.device.memory.changed', { 'lk.device.memory.pressure': next.memory }]); + } + // On charging change, and when the level crosses 20 % or 10 % unplugged — never per percent. + const crossed = (threshold: number) => + prev.batteryCharge !== undefined && + next.batteryCharge !== undefined && + prev.batteryCharge > threshold !== next.batteryCharge > threshold; + if ( + next.batteryState !== undefined && + (changed('batteryState') || (unplugged(next) && (crossed(0.2) || crossed(0.1)))) + ) { + out.push([ + 'lk.device.battery.changed', + { 'hw.battery.charge': next.batteryCharge, 'hw.battery.state': next.batteryState }, + ]); + } + return out; +} + +/** `NetworkInformation.type` → SPEC's enum. */ +const NETWORK: Record = { + wifi: 'wifi', + bluetooth: 'bluetooth', + other: 'other', + cellular: 'cell', + ethernet: 'wired', + none: 'unavailable', +}; + +/** Everything a page can answer: visibility, online/offline, and the connection on Chromium. Returns the stop function. */ +export function observeBrowser(report: (state: DeviceState) => void): () => void { + if (typeof document === 'undefined' || typeof window === 'undefined') return () => {}; + const { connection } = navigator as { + connection?: EventTarget & { type?: string; saveData?: boolean }; + }; + const update = () => + report({ + appState: document.visibilityState === 'hidden' ? 'background' : 'foreground', + networkType: + navigator.onLine === false ? 'unavailable' : (NETWORK[connection?.type ?? ''] ?? 'unknown'), + networkExpensive: connection ? connection.type === 'cellular' : undefined, + networkConstrained: connection ? connection.saveData === true : undefined, + }); + document.addEventListener('visibilitychange', update); + window.addEventListener('online', update); + window.addEventListener('offline', update); + connection?.addEventListener('change', update); + update(); + return () => { + document.removeEventListener('visibilitychange', update); + window.removeEventListener('online', update); + window.removeEventListener('offline', update); + connection?.removeEventListener('change', update); + }; +} + +/** The getUserMedia failure taxonomy, from a `DOMException` name (SPEC `lk.device.capture.failed`). */ +const CAPTURE_REASONS: Record = { + NotAllowedError: 'permission_denied', + PermissionDeniedError: 'permission_denied', + SecurityError: 'permission_denied', + NotFoundError: 'not_found', + DevicesNotFoundError: 'not_found', + OverconstrainedError: 'not_found', + NotReadableError: 'in_use', + TrackStartError: 'in_use', + AbortError: 'in_use', +}; + +export const captureFailureReason = (error: unknown) => + (error instanceof Error && CAPTURE_REASONS[error.name]) || 'other'; From 410c1e9c50fe1db138214da98933ee309bee860a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 4/7] feat(telemetry): expose opt-out, custom events and the host seam disableTelemetry() takes effect when it returns, purges the pipeline's and the configured host's cache, closes every open span and keeps later Rooms silent; it is a TODO pending the token discussion. configureTelemetryHost() is the @internal seam a platform such as React Native uses to supply resource names, a storage and a device observer. Every entry point called from SDK code is guarded, and the guard's own diagnosis cannot throw, so telemetry never surfaces in an app. On a runtime without WeakRef the pipeline starts disabled. --- src/index.ts | 9 +++ src/telemetry/index.ts | 175 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 184 insertions(+) create mode 100644 src/telemetry/index.ts diff --git a/src/index.ts b/src/index.ts index 4fa1329baa..d57f147243 100644 --- a/src/index.ts +++ b/src/index.ts @@ -201,3 +201,12 @@ export { type SerializerOutput, serializers, } from './utils/serializer'; + +export { disableTelemetry } from './telemetry'; +// @internal: the one seam a non-browser host (React Native) wires; not public API. +export { + configureTelemetryHost, + type TelemetryHost, + type TelemetryStorage, + type DeviceState as TelemetryDeviceState, +} from './telemetry'; diff --git a/src/telemetry/index.ts b/src/telemetry/index.ts new file mode 100644 index 0000000000..8a21ede3f0 --- /dev/null +++ b/src/telemetry/index.ts @@ -0,0 +1,175 @@ +/** + * Client telemetry: the pipeline the native SDKs get from the Rust core (`livekit-telemetry/SPEC.md` + * in rust-sdks is the contract), in TypeScript. One pipeline per process, installed with the first + * Room; one scope per Room. Public API: `disableTelemetry()`, `Room.emitTelemetryEvent()`, + * `Room.setTelemetryAttribute()`; `configureTelemetryHost()` is the one internal seam React Native wires. + */ +import { LOG_OWNER, LogLevel, setLogCapture } from '../logger'; +import { getBrowser } from '../utils/browserParser'; +import { version } from '../version'; +import { type DeviceState, captureFailureReason, observeBrowser } from './device'; +import { type Attributes, mask } from './otlp'; +import { Pipeline } from './pipeline'; +import { type PeerStatsSource, StatsPoller } from './poller'; +import { TelemetryScope, diagnose, guarded } from './scope'; +import type { TelemetryStorage } from './storage'; + +export type { DeviceState } from './device'; +export type { Attributes } from './otlp'; +export type { PeerStatsSource, StatsPoller } from './poller'; +export type { TelemetryScope, TelemetrySpan, SpanTrack } from './scope'; +export { disconnectReasonName } from './scope'; +export type { TelemetryStorage } from './storage'; +export type { TrackRef } from './webrtc'; + +/** + * @internal + * What a non-browser host supplies, once at app start before its first Room: React Native sets + * `sdk` (resource names), `storage` (a file-backed cache) and `observeDevice` (the state a phone + * can see, reported on change with its initial value, plus the device events a page cannot observe). + * Local e2e runs set `endpoint`, a collector base URL that receives everything without Cloud rules + * or tokens (the `LK_TELEMETRY_ENDPOINT` of the native cores). + */ +export interface TelemetryHost { + sdk?: { name: string; version: string; os?: string; osVersion?: string; deviceModel?: string }; + storage?: TelemetryStorage; + /** Returns the stop function. Without it, the browser's visibility and connection are observed. */ + observeDevice?: ( + report: (state: DeviceState) => void, + event: (name: string, attributes: Attributes) => void, + ) => (() => void) | void; + endpoint?: string; +} + +const pipeline = new Pipeline(); +/** The Room's scope, reachable from its local participant without a field on the public class. */ +const scopes = new WeakMap(); +let host: TelemetryHost = {}; +let installed = false; +let stopDevice: (() => void) | undefined; + +function onLog(level: LogLevel, message: unknown, context?: object, logger?: string) { + if (pipeline.disabled || level < LogLevel.warn) return; + const body = mask(String(message)); + const severity = level === LogLevel.error ? 'error' : 'warn'; + const carried = (context as Record | undefined)?.[LOG_OWNER]; + const owner = carried instanceof WeakRef ? carried.deref() : carried; + const roomShaped = context !== undefined && ('roomID' in context || 'room' in context); + // A line is its Room's by identity only: the Room's logger carries its scope. A Room-shaped + // context with no scope behind it is nobody's, dropped and counted; a line with no Room context + // at all is the process's. + if (owner instanceof TelemetryScope) owner.log(severity, body, logger ?? 'livekit'); + else if (roomShaped) pipeline.count('dropped.unattributed'); + else pipeline.log(severity, body, logger ?? 'livekit'); +} + +function applyHost() { + pipeline.endpoint = host.endpoint; + if (host.storage) pipeline.storage = host.storage; + const browser = host.sdk ? undefined : getBrowser(); + pipeline.resource = { + 'service.name': `livekit-client-${host.sdk?.name ?? 'js'}`, + 'service.version': host.sdk?.version ?? version, + 'telemetry.sdk.name': 'livekit-telemetry', + 'telemetry.sdk.language': 'webjs', + 'telemetry.sdk.version': '0.1.0', + 'os.name': host.sdk?.os, + 'os.version': host.sdk?.osVersion, + 'device.model.identifier': host.sdk?.deviceModel, + 'browser.name': browser?.name, + 'browser.version': browser?.version, + }; + stopDevice?.(); + const report = (state: DeviceState) => pipeline.deviceState(state); + const event = (name: string, attributes: Attributes) => pipeline.emit(name, attributes); + stopDevice = (host.observeDevice?.(report, event) ?? observeBrowser(report)) || undefined; +} + +/** Nothing called from SDK code may throw into it: the pipeline fails open, never the Room. */ +function quiet(run: () => T, fallback: T): T { + try { + return run(); + } catch (error) { + diagnose({ error }); + return fallback; + } +} + +function install() { + if (installed) return; + installed = true; + if (pipeline.disabled) return; + quiet(() => { + applyHost(); + setLogCapture(onLog); + pipeline.start(); + if (typeof window !== 'undefined') { + // The page's last chance; `fetch(keepalive)` makes it best effort. + window.addEventListener('pagehide', () => pipeline.flush(true).catch(() => {})); + } + }, undefined); +} + +/** @internal */ +export function configureTelemetryHost(next: TelemetryHost) { + host = next; + if (pipeline.disabled) + quiet(() => next.storage?.clear(), undefined); // opted out: nothing cached survives + else if (installed) quiet(applyHost, undefined); +} + +/** + * Opts this process out of client telemetry. In effect when the call returns: no Room collects + * anything more, nothing is uploaded, and everything not yet sent is deleted. Not remembered + * across launches, so call it on every start before the first Room. + * + * TODO: final shape pending the token/consent discussion. + */ +export function disableTelemetry(): void { + // Before the first Room the host's cache (a previous launch's batches) is not installed yet: it + // is purged all the same. + if (host.storage) pipeline.storage = host.storage; + pipeline.disable(); + installed = true; + quiet(() => { + stopDevice?.(); + stopDevice = undefined; + setLogCapture(undefined); + }, undefined); +} + +/** @internal What the SDK calls: every entry point and every object handed out is guarded. */ +export const telemetry = { + pipeline, + + scope(): TelemetryScope { + install(); + return guarded(new TelemetryScope(pipeline)); + }, + + poller(scope: TelemetryScope, source: PeerStatsSource): StatsPoller { + return guarded(new StatsPoller(scope, pipeline, source)); + }, + + bind(owner: object, scope: TelemetryScope) { + scopes.set(owner, scope); + }, + + scopeOf(owner: object): TelemetryScope | undefined { + return scopes.get(owner); + }, + + /** What a log context carries for the Room's scope: weak, so a retained context never keeps a Room alive. */ + carrier(scope: TelemetryScope | undefined): WeakRef | undefined { + return scope && typeof WeakRef !== 'undefined' ? new WeakRef(scope) : undefined; + }, + + /** A getUserMedia / getDisplayMedia failure (SPEC `lk.device.capture.failed`). */ + captureFailed(error: unknown, device: 'camera' | 'microphone' | 'screen_share') { + quiet(() => { + const reason = captureFailureReason(error); + const attributes = { 'lk.device.capture.device': device, 'lk.device.capture.reason': reason }; + pipeline.emit('lk.device.capture.failed', attributes, 'warn'); + }, undefined); + }, +}; From 720df34a13fd0cd1ba52a40cb0ccd44630c980e0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 5/7] feat(telemetry): instrument Room, engine and signal client Room installs the pipeline on construction, opens its scope on connect, forwards the join token and every refreshed token, records the required connect checkpoints in order, and ends the connect, reconnect, publish and subscribe spans with the outcome the engine and signal client report. Publishes and republishes share one instrumented path, so a full reconnect's republishes are spans and warnings during a publish carry its id. Room.emitTelemetryEvent() and Room.setTelemetryAttribute() are the two public additions; the local participant reaches its Room's scope through a WeakMap so the emitted declarations expose nothing else. --- src/api/SignalClient.ts | 4 + src/e2ee/E2eeManager.ts | 11 +- src/room/RTCEngine.ts | 23 +++- src/room/Room.ts | 147 ++++++++++++++++++++++- src/room/events.ts | 2 + src/room/participant/LocalParticipant.ts | 31 ++++- 6 files changed, 206 insertions(+), 12 deletions(-) diff --git a/src/api/SignalClient.ts b/src/api/SignalClient.ts index 0244f82ef5..a2a6b9d99e 100644 --- a/src/api/SignalClient.ts +++ b/src/api/SignalClient.ts @@ -224,6 +224,9 @@ export class SignalClient { onTokenRefresh?: (token: string) => void; + /** @internal The WebSocket upgrade completed (telemetry's `ws_open` checkpoint). */ + onWebSocketOpen?: () => void; + onLeave?: (leave: LeaveRequest) => void; onRequestResponse?: (response: RequestResponse) => void; @@ -578,6 +581,7 @@ export class SignalClient { if (!connection) { return; } + this.onWebSocketOpen?.(); const signalReader = connection.readable.getReader(); this.streamWriter = connection.writable.getWriter(); diff --git a/src/e2ee/E2eeManager.ts b/src/e2ee/E2eeManager.ts index f9f6f7b7b6..608907838a 100644 --- a/src/e2ee/E2eeManager.ts +++ b/src/e2ee/E2eeManager.ts @@ -3,7 +3,14 @@ import { EventEmitter } from 'events'; import type TypedEventEmitter from 'typed-emitter'; import type { FrameMetadata } from '../frameMetadata/types'; import { hasFrameMetadataPublishOptions } from '../frameMetadata/utils'; -import { LogLevel, LoggerNames, getLogger, onWorkerLogLevelChanged, workerLogger } from '../logger'; +import { + LOG_OWNER, + LogLevel, + LoggerNames, + getLogger, + onWorkerLogLevelChanged, + workerLogger, +} from '../logger'; import type RTCEngine from '../room/RTCEngine'; import type Room from '../room/Room'; import { ConnectionState } from '../room/Room'; @@ -22,6 +29,7 @@ import { isScriptTransformSupportedForWorker, isVideoTrack, } from '../room/utils'; +import { telemetry } from '../telemetry'; import type { NonSharedUint8Array } from '../type-polyfills/non-shared-typed-arrays'; import type { BaseKeyProvider } from './KeyProvider'; import { E2EE_FLAG, E2EE_TRACK_ID } from './constants'; @@ -97,6 +105,7 @@ export class E2EEManager return { room: this.room?.name, participant: this.room?.localParticipant.identity, + [LOG_OWNER]: this.room ? telemetry.carrier(telemetry.scopeOf(this.room)) : undefined, }; } diff --git a/src/room/RTCEngine.ts b/src/room/RTCEngine.ts index e31db71aa3..d74ff6e9f8 100644 --- a/src/room/RTCEngine.ts +++ b/src/room/RTCEngine.ts @@ -60,7 +60,7 @@ import { isFrameMetadataSupported, shouldUseFrameMetadataScriptTransform, } from '../frameMetadata/utils'; -import log, { LoggerNames, getLogger } from '../logger'; +import log, { LOG_OWNER, LoggerNames, getLogger } from '../logger'; import type { InternalRoomOptions } from '../options'; import type { NonSharedUint8Array } from '../type-polyfills/non-shared-typed-arrays'; import TypedPromise from '../utils/TypedPromise'; @@ -221,6 +221,9 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit private reconnectAttempts: number = 0; + /** Why the current reconnect started — the two events below carry it to telemetry. */ + private reconnectReason?: ReconnectReason; + private reconnectStart: number = 0; private clientConfiguration?: ClientConfiguration; @@ -328,12 +331,16 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit } /** @internal */ + /** @internal The Room this engine serves (looked up lazily: the engine exists before the Room's scope), for telemetry to file its warnings by identity. */ + logOwner?: () => object | undefined; + get logContext() { return { room: this.latestJoinResponse?.room?.name, roomID: this.latestJoinResponse?.room?.sid, participant: this.latestJoinResponse?.participant?.identity, participantID: this.participantSid, + [LOG_OWNER]: this.logOwner?.(), }; } @@ -737,6 +744,10 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit this.emit(EngineEvent.TokenRefreshed, token); }; + this.client.onWebSocketOpen = () => { + this.emit(EngineEvent.SignalOpened); + }; + this.client.onRemoteMuteChanged = (trackSid: string, muted: boolean) => { this.emit(EngineEvent.RemoteMute, trackSid, muted); }; @@ -1309,6 +1320,7 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit if (this._isClosed) { return; } + this.reconnectReason = reason; // guard for attempting reconnection multiple times while one attempt is still not finished if (this.attemptingReconnect) { this.log.warn('already attempting reconnect, returning early'); @@ -1406,7 +1418,7 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit } this.log.info(`reconnecting, attempt: ${this.reconnectAttempts}`); - this.emit(EngineEvent.Restarting); + this.emit(EngineEvent.Restarting, this.reconnectReason); if (!this.client.isDisconnected) { await this.client.sendLeave(); @@ -1479,7 +1491,7 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit } this.log.info(`resuming signal connection, attempt ${this.reconnectAttempts}`); - this.emit(EngineEvent.Resuming); + this.emit(EngineEvent.Resuming, this.reconnectReason); let res: ReconnectResponse | undefined; try { this.setupSignalClientCallbacks(); @@ -2070,12 +2082,13 @@ export default class RTCEngine extends (EventEmitter as new () => TypedEventEmit export type EngineEventCallbacks = { connected: (joinResp: JoinResponse) => void; disconnected: (reason?: DisconnectReason) => void; - resuming: () => void; + resuming: (reason?: ReconnectReason) => void; resumed: () => void; - restarting: () => void; + restarting: (reason?: ReconnectReason) => void; restarted: () => void; signalResumed: () => void; signalRestarted: (joinResp: JoinResponse) => void; + signalOpened: () => void; closing: () => void; mediaTrackAdded: ( track: MediaStreamTrack, diff --git a/src/room/Room.ts b/src/room/Room.ts index 6eba0bb000..f81acc5f2d 100644 --- a/src/room/Room.ts +++ b/src/room/Room.ts @@ -14,6 +14,7 @@ import { ParticipantInfo, ParticipantInfo_State, ParticipantPermission, + ReconnectReason, Room as RoomModel, ServerInfo, SimulateScenario, @@ -39,13 +40,21 @@ import { EncryptionEvent } from '../e2ee'; import { type BaseE2EEManager, E2EEManager } from '../e2ee/E2eeManager'; import { FrameMetadataManager } from '../frameMetadata/FrameMetadataManager'; import { isFrameMetadataSupported } from '../frameMetadata/utils'; -import log, { LoggerNames, getLogger } from '../logger'; +import log, { LOG_OWNER, LoggerNames, getLogger } from '../logger'; import type { InternalRoomConnectOptions, InternalRoomOptions, RoomConnectOptions, RoomOptions, } from '../options'; +import { + type SpanTrack, + type StatsPoller, + type TelemetryScope, + type TrackRef, + disconnectReasonName, + telemetry, +} from '../telemetry'; import type { NonSharedUint8Array } from '../type-polyfills/non-shared-typed-arrays'; import TypedPromise from '../utils/TypedPromise'; import { getBrowser } from '../utils/browserParser'; @@ -101,7 +110,7 @@ import LocalVideoTrack from './track/LocalVideoTrack'; import type RemoteTrack from './track/RemoteTrack'; import RemoteTrackPublication from './track/RemoteTrackPublication'; import { Track } from './track/Track'; -import type { TrackPublication } from './track/TrackPublication'; +import { TrackPublication } from './track/TrackPublication'; import type { TrackProcessor } from './track/processor/types'; import type { AdaptiveStreamSettings } from './track/types'; import { getNewAudioContext, kindToSource, sourceToKind } from './track/utils'; @@ -200,6 +209,15 @@ class Room extends (EventEmitter as new () => TypedEmitter) /** future holding client initiated connection attempt */ private connectFuture?: Future; + /** This room's telemetry session: one trace id for the room's lifetime, across connects. */ + private readonly telemetry: TelemetryScope; + + /** The weak carrier of the scope for this Room's log contexts. */ + private telemetryRef: WeakRef | undefined; + + /** One `getStats()` per peer connection, paced by telemetry; runs only while connected. */ + private statsPoller: StatsPoller; + private disconnectLock: Mutex; private e2eeManager: BaseE2EEManager | undefined; @@ -365,6 +383,14 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.rpcClientManager, this.rpcServerManager, ); + this.telemetry = telemetry.scope(); + telemetry.bind(this, this.telemetry); + telemetry.bind(this.localParticipant, this.telemetry); + this.telemetryRef = telemetry.carrier(this.telemetry); + this.statsPoller = telemetry.poller(this.telemetry, { + peers: () => [this.engine?.pcManager?.publisher, this.engine?.pcManager?.subscriber], + tracks: () => this.telemetryTracks(), + }); this.setupFrameMetadata(); @@ -549,6 +575,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) roomID: this.roomInfo?.sid, participant: this.localParticipant?.identity, participantID: this.localParticipant?.sid, + [LOG_OWNER]: this.telemetryRef, // telemetry files the line under this Room by identity, not by name }; } @@ -611,6 +638,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) } this.engine = new RTCEngine(this.options); + this.engine.logOwner = () => this.telemetryRef; this.engine.e2eeManager = this.e2eeManager; this.engine @@ -632,7 +660,8 @@ class Room extends (EventEmitter as new () => TypedEmitter) }) .on(EngineEvent.ActiveSpeakersUpdate, this.handleActiveSpeakersUpdate) .on(EngineEvent.DataPacketReceived, this.handleDataPacket) - .on(EngineEvent.Resuming, () => { + .on(EngineEvent.Resuming, (reason?: ReconnectReason) => { + this.telemetry.reconnectAttempt('quick', reason); this.clearConnectionReconcile(); this.isResuming = true; this.log.debug('Resuming signal connection'); @@ -641,6 +670,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) } }) .on(EngineEvent.Resumed, () => { + this.telemetry.reconnectEnded('ok'); this.registerConnectionReconcile(); this.isResuming = false; this.log.debug('Resumed signal connection'); @@ -672,6 +702,10 @@ class Room extends (EventEmitter as new () => TypedEmitter) }) .on(EngineEvent.RoomMoved, (roomMoved) => { this.log.debug('room moved', roomMoved); + if (roomMoved.token) { + this.telemetry.refreshToken(roomMoved.token); + } + this.telemetry.setRoom({ participantSid: roomMoved.participant?.sid }); if (roomMoved.room) { this.handleRoomUpdate(roomMoved.room); @@ -749,7 +783,14 @@ class Room extends (EventEmitter as new () => TypedEmitter) }) .on(EngineEvent.TokenRefreshed, (token) => { this.regionUrlProvider?.updateToken(token); + this.telemetry.refreshToken(token); }) + .on(EngineEvent.SignalOpened, () => { + // The join request goes out on the open socket; its answer is `join_recv`. + this.telemetry.connectStep('ws_open'); + this.telemetry.connectStep('signal'); + }) + .on(EngineEvent.TransportsCreated, () => this.telemetry.connectStep('pc_created')) .on(EngineEvent.ServerRegionsReported, (regions) => { this.regionUrlProvider?.setServerReportedRegions({ regionSettings: regions, @@ -858,6 +899,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) } this.setAndEmitConnectionState(ConnectionState.Connecting); + this.telemetry.connectStarted(url, token); if (this.regionUrlProvider?.getServerUrl().toString() !== ensureTrailingSlash(url)) { this.regionUrl = undefined; this.regionUrlProvider = undefined; @@ -923,6 +965,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) (regionFetchError.status === 401 || regionFetchError.reason === ConnectionErrorReason.Cancelled) ) { + this.endConnectSpan(regionFetchError); this.handleDisconnect(this.options.stopLocalTrackOnUnpublish); reject(regionFetchError); return; @@ -946,6 +989,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.recreateEngine(true); await connectFn(resolve, reject, nextUrl); } else { + this.endConnectSpan(error); this.handleDisconnect( this.options.stopLocalTrackOnUnpublish, getDisconnectReasonFromConnectionError(error), @@ -957,6 +1001,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) if (error instanceof ConnectionError) { disconnectReason = getDisconnectReasonFromConnectionError(error); } + this.endConnectSpan(error); this.handleDisconnect(this.options.stopLocalTrackOnUnpublish, disconnectReason); reject(error); } @@ -1022,6 +1067,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.localParticipant.sid = pi.sid; this.localParticipant.identity = pi.identity; + this.telemetry.setRoom({ participantSid: pi.sid, participantIdentity: pi.identity }); this.localParticipant.setEnabledPublishCodecs(joinResponse.enabledPublishCodecs); if (this.e2eeManager) { @@ -1040,6 +1086,14 @@ class Room extends (EventEmitter as new () => TypedEmitter) if (joinResponse.room) { this.handleRoomUpdate(joinResponse.room); } + // Tracks already in the room: the intent to subscribe exists from the join (SPEC `lk.subscribe`). + this.remoteParticipants.forEach((participant) => + participant.trackPublications.forEach((pub) => { + if (pub.isDesired && !pub.isSubscribed) { + this.telemetry.subscribeStarted(this.telemetryTrack(pub, participant)); + } + }), + ); }; private attemptConnection = async ( @@ -1084,6 +1138,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.options, abortController, ); + this.telemetry.connectStep('join_recv'); this.applyJoinResponse(joinResponse); // forward metadata changed for the local participant @@ -1121,6 +1176,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.connOptions.peerConnectionTimeout, abortController, ); + this.telemetry.connectStep('pc_connected'); } catch (e) { await this.engine.close(); this.recreateEngine(); @@ -1137,6 +1193,9 @@ class Room extends (EventEmitter as new () => TypedEmitter) window.addEventListener('freeze', this.onPageLeave); } this.setAndEmitConnectionState(ConnectionState.Connected); + this.telemetry.connectStep('room_connected'); + this.telemetry.connectEnded('ok'); + this.statsPoller.start(); this.emit(RoomEvent.Connected); BackOffStrategy.getInstance().resetFailedConnectionAttempts(url); this.registerConnectionReconcile(); @@ -1781,7 +1840,8 @@ class Room extends (EventEmitter as new () => TypedEmitter) this.emitWhenConnected(RoomEvent.LocalTrackSubscribed, trackPublication, this.localParticipant); } - private handleRestarting = () => { + private handleRestarting = (reason?: ReconnectReason) => { + this.telemetry.reconnectAttempt('full', reason); this.clearConnectionReconcile(); // in case we went from resuming to full-reconnect, make sure to reflect it on the isResuming flag this.isResuming = false; @@ -1824,11 +1884,59 @@ class Room extends (EventEmitter as new () => TypedEmitter) return; } this.setAndEmitConnectionState(ConnectionState.Connected); + this.telemetry.reconnectEnded('ok'); this.emit(RoomEvent.Reconnected); this.registerConnectionReconcile(); this.emitBufferedEvents(); }; + private endConnectSpan(error: unknown) { + const cancelled = + error instanceof ConnectionError && error.reason === ConnectionErrorReason.Cancelled; + this.telemetry.connectEnded(cancelled ? 'cancelled' : 'error', error); + } + + /** @internal `MediaStreamTrack` id → the room's published and subscribed tracks, for the stats poller. */ + private telemetryTracks(): Map { + const tracks = new Map(); + const add = (pub: TrackPublication, direction: TrackRef['direction']) => { + const kind = pub.kind === Track.Kind.Audio ? 'audio' : 'video'; + if (pub.track) + tracks.set(pub.track.mediaStreamTrack.id, { sid: pub.trackSid, kind, direction }); + }; + this.localParticipant.trackPublications.forEach((pub) => add(pub, 'outbound')); + this.remoteParticipants.forEach((p) => + p.trackPublications.forEach((pub) => add(pub, 'inbound')), + ); + return tracks; + } + + private telemetryTrack(pub: RemoteTrackPublication, participant: RemoteParticipant): SpanTrack { + return { + sid: pub.trackSid, + kind: pub.kind === Track.Kind.Audio ? 'audio' : 'video', + source: pub.source, + remoteIdentity: participant.identity, + }; + } + + /** + * Reports an app-defined telemetry event under this room's session, exported as `custom.`. + * Names and keys up to 128 bytes, string values up to 1024 bytes, 64 attributes at most; anything + * over a limit, or an `lk.*` key, is dropped and counted, never truncated. + */ + emitTelemetryEvent(name: string, attributes: Record = {}): void { + this.telemetry.emitCustom(name, attributes); + } + + /** + * Sets a correlation attribute (`app.call_id`, `enduser.id`, …) carried by this room's subsequent + * telemetry records; `null` removes it. Same limits as {@link emitTelemetryEvent}. + */ + setTelemetryAttribute(key: string, value: string | null): void { + this.telemetry.setAttribute(key, value); + } + private handleDisconnect(shouldStopTracks = true, reason?: DisconnectReason) { this.clearConnectionReconcile(); this.isResuming = false; @@ -1841,6 +1949,15 @@ class Room extends (EventEmitter as new () => TypedEmitter) return; } + // An engine that gave up reconnecting reports no reason of its own (SPEC `reconnect_failed`). + const gaveUp = reason === undefined && this.telemetry.reconnecting; + const clientInitiated = reason === DisconnectReason.CLIENT_INITIATED; + const cause = gaveUp ? 'reconnect_failed' : disconnectReasonName(reason); + this.statsPoller.stop(); + this.telemetry.connectEnded(clientInitiated ? 'cancelled' : 'error', cause); + this.telemetry.reconnectEnded(clientInitiated ? 'cancelled' : 'error', cause); + this.telemetry.disconnected(reason, gaveUp ? cause : undefined); + this.regionUrl = undefined; // Notify region provider about disconnect to potentially stop auto-refetch @@ -2328,6 +2445,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) private handleRoomUpdate = (room: RoomModel) => { const oldRoom = this.roomInfo; this.roomInfo = room; + this.telemetry.setRoom({ sid: room.sid, name: room.name }); if (oldRoom && oldRoom.metadata !== room.metadata) { this.emitWhenConnected(RoomEvent.RoomMetadataChanged, room.metadata); } @@ -2445,6 +2563,9 @@ class Room extends (EventEmitter as new () => TypedEmitter) // and remote participant joined the room participant .on(ParticipantEvent.TrackPublished, (trackPublication: RemoteTrackPublication) => { + if (trackPublication.isDesired) { + this.telemetry.subscribeStarted(this.telemetryTrack(trackPublication, participant)); + } this.emitWhenConnected(RoomEvent.TrackPublished, trackPublication, participant); }) .on( @@ -2458,16 +2579,19 @@ class Room extends (EventEmitter as new () => TypedEmitter) track.on(TrackEvent.VideoPlaybackFailed, this.handleVideoPlaybackFailed); track.on(TrackEvent.VideoPlaybackStarted, this.handleVideoPlaybackStarted); } + this.telemetry.subscribed(this.telemetryTrack(publication, participant)); this.emitWhenConnected(RoomEvent.TrackSubscribed, track, publication, participant); }, ) .on(ParticipantEvent.TrackUnpublished, (publication: RemoteTrackPublication) => { this.cancelPendingTrackAdded(publication.trackSid); + this.telemetry.trackEnded(publication.trackSid); this.emit(RoomEvent.TrackUnpublished, publication, participant); }) .on( ParticipantEvent.TrackUnsubscribed, (track: RemoteTrack, publication: RemoteTrackPublication) => { + this.telemetry.trackEnded(publication.trackSid); this.emit(RoomEvent.TrackUnsubscribed, track, publication, participant); }, ) @@ -2504,9 +2628,21 @@ class Room extends (EventEmitter as new () => TypedEmitter) }, ) .on(ParticipantEvent.TrackSubscriptionStatusChanged, (pub, status) => { + // A manual `setSubscribed(true)` is an intent; `setSubscribed(false)` before media ends it. + if (status === TrackPublication.SubscriptionStatus.Desired) { + this.telemetry.subscribeStarted(this.telemetryTrack(pub, participant)); + } else if (status === TrackPublication.SubscriptionStatus.Unsubscribed) { + this.telemetry.trackEnded(pub.trackSid); + } this.emitWhenConnected(RoomEvent.TrackSubscriptionStatusChanged, pub, status, participant); }) .on(ParticipantEvent.TrackSubscriptionFailed, (trackSid, error) => { + this.telemetry.subscribeFailed( + trackSid, + (SubscriptionError[error ?? SubscriptionError.SE_UNKNOWN] ?? 'SE_UNKNOWN') + .replace(/^SE_/, '') + .toLowerCase(), + ); this.emit(RoomEvent.TrackSubscriptionFailed, trackSid, participant, error); }) .on(ParticipantEvent.TrackSubscriptionPermissionChanged, (pub, status) => { @@ -2770,6 +2906,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) pub.track?.on(TrackEvent.TrackProcessorUpdate, this.onTrackProcessorUpdate); pub.track?.on(TrackEvent.Restarted, this.onLocalTrackRestarted); pub.track?.getProcessor()?.onPublish?.(this); + this.telemetry.trackPublished(pub.trackSid); this.emit(RoomEvent.LocalTrackPublished, pub, this.localParticipant); @@ -2794,6 +2931,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) private onLocalTrackUnpublished = (pub: LocalTrackPublication) => { pub.track?.off(TrackEvent.TrackProcessorUpdate, this.onTrackProcessorUpdate); pub.track?.off(TrackEvent.Restarted, this.onLocalTrackRestarted); + this.telemetry.trackEnded(pub.trackSid); this.emit(RoomEvent.LocalTrackUnpublished, pub, this.localParticipant); }; @@ -2816,6 +2954,7 @@ class Room extends (EventEmitter as new () => TypedEmitter) }; private onMediaDevicesError = (e: Error, kind?: MediaDeviceKind) => { + telemetry.captureFailed(e, kind === 'videoinput' ? 'camera' : 'microphone'); this.emit(RoomEvent.MediaDevicesError, e, kind); }; diff --git a/src/room/events.ts b/src/room/events.ts index f4580f4b16..87787375dd 100644 --- a/src/room/events.ts +++ b/src/room/events.ts @@ -625,6 +625,8 @@ export enum EngineEvent { Offline = 'offline', SignalRequestResponse = 'signalRequestResponse', SignalConnected = 'signalConnected', + /** @internal The signal WebSocket upgrade completed; a telemetry checkpoint. */ + SignalOpened = 'signalOpened', RoomMoved = 'roomMoved', PublishDataTrackResponse = 'publishDataTrackResponse', UnPublishDataTrackResponse = 'unPublishDataTrackResponse', diff --git a/src/room/participant/LocalParticipant.ts b/src/room/participant/LocalParticipant.ts index 645482c224..f010aacce4 100644 --- a/src/room/participant/LocalParticipant.ts +++ b/src/room/participant/LocalParticipant.ts @@ -30,6 +30,7 @@ import { isFrameMetadataSupported, } from '../../frameMetadata/utils'; import type { InternalRoomOptions } from '../../options'; +import { telemetry } from '../../telemetry'; import type { NonSharedUint8Array } from '../../type-polyfills/non-shared-typed-arrays'; import TypedPromise from '../../utils/TypedPromise'; import { PCTransportState } from '../PCTransportManager'; @@ -778,7 +779,33 @@ export default class LocalParticipant extends Participant { * @param options */ async publishTrack(track: LocalTrack | MediaStreamTrack, options?: TrackPublishOptions) { - return this.publishOrRepublishTrack(track, options); + return this.publishSpanned(track, options, false); + } + + /** One `lk.publish` span per attempt, republishes included; nested under the open connect/reconnect span, when any. */ + private async publishSpanned( + track: LocalTrack | MediaStreamTrack, + options: TrackPublishOptions | undefined, + isRepublish: boolean, + ) { + const scope = telemetry.scopeOf(this); + const span = scope?.start('lk.publish', { + parent: scope.uplink(), + attributes: { + 'lk.track.kind': track.kind, + 'lk.track.source': 'source' in track ? track.source : undefined, + }, + }); + try { + const publication = await this.publishOrRepublishTrack(track, options, isRepublish); + span?.setAttribute('lk.track.sid', publication.trackSid); + span?.setAttribute('lk.track.source', publication.source); + span?.end('ok'); + return publication; + } catch (error) { + span?.fail(error); + throw error; + } } /** @@ -1721,7 +1748,7 @@ export default class LocalParticipant extends Participant { this.log.debug('restarting existing track', { track: pub.trackSid }); await track.restartTrack(); } - await this.publishOrRepublishTrack(track, pub.options, true); + await this.publishSpanned(track, pub.options, true); }), ); resolve(); From e712e1d749d316a2f9e9c948f472be386b8d1981 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 6/7] test(telemetry): unit tests and the collector story Unit tests cover the collector-answer table, record ownership across projects and reconnects, cache bounds, fallbacks and losses, delete markers, masking, the opt-out before and after install, the poller gate and generation, window closure and cadence relief, and the per-layer fold. The e2e suite gains the telemetry story in Chromium: two Rooms on livekit-server --dev, mock media, every span lifecycle including failed and cancelled connects and republishes, reconnects, a refreshed token, a custom event and attribute, device events, disconnect and the opt-out, with every batch posted to an OTLP collector. It skips locally when a service is unreachable and fails on CI, where both run as services. --- .github/workflows/e2e.yaml | 25 + src/telemetry/optOut.test.ts | 31 + src/telemetry/telemetry.browser.test.ts | 275 ++++ src/telemetry/telemetry.test.ts | 1612 +++++++++++++++++++++++ src/telemetry/telemetrySetup.ts | 61 + vite.config.mjs | 2 +- vitest.e2e.config.mts | 29 +- vitest.telemetry.config.mts | 13 + 8 files changed, 2039 insertions(+), 9 deletions(-) create mode 100644 src/telemetry/optOut.test.ts create mode 100644 src/telemetry/telemetry.browser.test.ts create mode 100644 src/telemetry/telemetry.test.ts create mode 100644 src/telemetry/telemetrySetup.ts create mode 100644 vitest.telemetry.config.mts diff --git a/.github/workflows/e2e.yaml b/.github/workflows/e2e.yaml index 8d89244230..135bbf2df2 100644 --- a/.github/workflows/e2e.yaml +++ b/.github/workflows/e2e.yaml @@ -24,6 +24,28 @@ jobs: image: livekit/test-server:latest ports: - 9999:9999 + # The telemetry story (src/telemetry/telemetry.browser.test.ts) runs a whole call on a real + # server and reports it to a real OTLP collector; without them it skips. + livekit: + image: livekit/livekit-server:latest + env: + LIVEKIT_KEYS: 'devkey: secret' + # media over the published ports only: one UDP port, candidates on 127.0.0.1 + LIVEKIT_CONFIG: | + port: 7880 + rtc: + tcp_port: 7881 + udp_port: 7882 + use_external_ip: false + node_ip: 127.0.0.1 + ports: + - 7880:7880 + - 7881:7881 + - 7882:7882/udp + otelcol: + image: otel/opentelemetry-collector-contrib:latest + ports: + - 4318:4318 steps: - uses: actions/checkout@d23441a48e516b6c34aea4fa41551a30e30af803 # v6.1.0 @@ -53,6 +75,9 @@ jobs: env: # Connect to the test-server service above (validate + WS on 9999). LK_TEST_SERVER_URL: ws://127.0.0.1:9999 + # The telemetry story's server and collector (services above). + LK_URL: ws://127.0.0.1:7880 + LK_TELEMETRY_ENDPOINT: http://127.0.0.1:4318 - name: Collect test-server logs if: failure() diff --git a/src/telemetry/optOut.test.ts b/src/telemetry/optOut.test.ts new file mode 100644 index 0000000000..78c1c027c2 --- /dev/null +++ b/src/telemetry/optOut.test.ts @@ -0,0 +1,31 @@ +import { expect, test, vi } from 'vitest'; + +/** + * The documented opt-out order, on a module nobody has installed yet: `disableTelemetry()` before + * the first Room, with a host cache from an earlier launch already configured. + */ +const b64 = (value: object) => btoa(JSON.stringify(value)).replace(/=+$/, ''); +const token = `${b64({ alg: 'HS256' })}.${b64({ exp: 4102444800, observability: { write: true } })}.sig`; + +test('an opt-out before anything installs the pipeline purges the host cache and silences later Rooms', async () => { + vi.resetModules(); + const { configureTelemetryHost, disableTelemetry, telemetry } = await import('.'); + const { MemoryStorage } = await import('./storage'); + const fetchMock = vi.fn(async () => new Response('', { status: 200 })); + vi.stubGlobal('fetch', fetchMock); + const stale = new MemoryStorage(1 << 20, 10); + stale.put('000000000000001_000001_3_l_proj-abc.livekit.cloud', new Uint8Array([1, 2, 3])); + configureTelemetryHost({ storage: stale }); + + disableTelemetry(); + + expect(stale.pending()).toEqual([]); + const room = telemetry.scope(); + room.setServer('wss://proj-abc.livekit.cloud', token); + room.emit('custom.after'); + await telemetry.pipeline.flush(true); + expect(telemetry.pipeline.enabled).toBe(false); + expect(telemetry.pipeline.stats()).toMatchObject({ cached: 0, queued: 0 }); + expect(fetchMock).not.toHaveBeenCalled(); + vi.unstubAllGlobals(); +}); diff --git a/src/telemetry/telemetry.browser.test.ts b/src/telemetry/telemetry.browser.test.ts new file mode 100644 index 0000000000..d78374e16c --- /dev/null +++ b/src/telemetry/telemetry.browser.test.ts @@ -0,0 +1,275 @@ +import { describe, expect, inject, test, vi } from 'vitest'; +import { configureTelemetryHost, disableTelemetry, telemetry } from '.'; +import { getLogger } from '../logger'; +import Room from '../room/Room'; +import { RoomEvent } from '../room/events'; +import { Track } from '../room/track/Track'; +import type { LogRecord, SpanRecord, TelemetryRecord } from './otlp'; + +/** + * The telemetry story, end to end in a real Chromium: a publisher and a subscriber on a real + * `livekit-server --dev`, every batch sent to a real OTLP collector (the local LGTM stack when it + * runs), and the records inspected as they are cached. Skips when either service is unreachable + * (see `telemetrySetup.ts`). + * + * pnpm test:e2e # with the signal e2e suite + * pnpm vitest run --config vitest.telemetry.config.mts # this story alone + */ +const { url, unavailable, publisherToken, subscriberToken } = inject('telemetry'); +// the collector, proxied through the page's origin by vitest.e2e.config.mts +const endpoint = `${location.origin}/__otlp`; + +const sleep = (ms: number) => new Promise((resolve) => setTimeout(resolve, ms)); +const once = (room: Room, event: RoomEvent) => + new Promise((resolve) => room.once(event, () => resolve())); + +/** A canvas and an oscillator: media that flows without a camera, a microphone or a permission. */ +function mockMedia() { + const canvas = document.createElement('canvas'); + canvas.width = 160; + canvas.height = 120; + const paint2d = canvas.getContext('2d')!; + let hue = 0; + const paint = () => { + hue = (hue + 7) % 360; + paint2d.fillStyle = `hsl(${hue} 80% 50%)`; + paint2d.fillRect(0, 0, canvas.width, canvas.height); + }; + paint(); + const painter = setInterval(paint, 66); + const audioContext = new AudioContext(); + const oscillator = audioContext.createOscillator(); + const destination = audioContext.createMediaStreamDestination(); + oscillator.connect(destination); + oscillator.start(); + return { + video: canvas.captureStream(15).getVideoTracks()[0], + audio: destination.stream.getAudioTracks()[0], + stop: () => { + clearInterval(painter); + oscillator.stop(); + audioContext.close().catch(() => {}); + }, + }; +} + +describe.skipIf(!!unavailable)('telemetry story', () => { + test('one call reports every span, window and event, then opts out', async () => { + configureTelemetryHost({ endpoint }); + const records: TelemetryRecord[] = []; + telemetry.pipeline.onBatch = (batch) => records.push(...batch); + const spans = (name: string) => + records.filter((r): r is SpanRecord => r.kind === 'span' && r.name === name); + const events = (name: string) => + records.filter((r): r is LogRecord => r.kind === 'log' && r.eventName === name); + const okSubscribes = () => + spans('lk.subscribe').filter((s) => s.attributes['lk.outcome'] === 'ok'); + const settle = async (what: string, condition: () => boolean, timeout = 20_000) => { + const deadline = Date.now() + timeout; + while (!condition()) { + if (Date.now() > deadline) throw new Error(`timed out waiting for ${what}`); + await telemetry.pipeline.flush(); + await sleep(250); + } + }; + const setServer = vi.spyOn(telemetry.pipeline, 'setServer'); + const marker = `e2e-${Date.now()}`; + + // connect, with a correlation attribute set before the first record + const publisher = new Room(); + publisher.setTelemetryAttribute('app.call_id', marker); + publisher.setTelemetryAttribute('lk.room.sid', 'spoof'); // reserved: rejected, counted + await publisher.connect(url, publisherToken); + const media = mockMedia(); + await publisher.localParticipant.publishTrack(media.audio, { + source: Track.Source.Microphone, + }); + + // a late joiner subscribes to the track the join announced, then to a later publish + const subscriber = new Room(); + await subscriber.connect(url, subscriberToken); + await settle('first media on the join-time subscribe', () => okSubscribes().length >= 1); + await publisher.localParticipant.publishTrack(media.video, { source: Track.Source.Camera }); + await settle('first media on the published track', () => okSubscribes().length >= 2); + + // a manual unsubscribe / subscribe is a new intent + const remote = Array.from(subscriber.remoteParticipants.values())[0]; + const microphone = remote.getTrackPublication(Track.Source.Microphone)!; + const unsubscribed = once(subscriber, RoomEvent.TrackUnsubscribed); + microphone.setSubscribed(false); + await unsubscribed; + microphone.setSubscribed(true); + await settle('first media on the manual subscribe', () => okSubscribes().length >= 3); + + // both reconnect paths + for (const scenario of ['resume-reconnect', 'full-reconnect'] as const) { + const reconnected = once(publisher, RoomEvent.Reconnected); + await publisher.simulateScenario(scenario); + await reconnected; + } + await settle('both reconnect spans', () => spans('lk.reconnect').length >= 2); + + // a refreshed token, through the path the SFU's own refresh takes (it arrives minutes later) + const servers = setServer.mock.calls.length; + publisher.engine.client.onTokenRefresh?.(publisherToken); + expect(setServer.mock.calls.length).toBe(servers + 1); + + // the app's event, an SDK warning, and the device state a browser cannot see + publisher.emitTelemetryEvent('e2e.checkpoint', { step: 'reconnected' }); + publisher.emitTelemetryEvent('', {}); // invalid: counted, never sent + // the Room's own logger: its line is the Room's by identity + (publisher as unknown as { log: { warn: (message: string) => void } }).log.warn( + 'e2e: a warning for telemetry', + ); + telemetry.pipeline.deviceState({ + thermal: 'serious', + lowPower: true, + memory: 'warning', + batteryCharge: 0.15, + batteryState: 'discharging', + networkType: 'cell', + networkExpensive: true, + }); + telemetry.pipeline.emit('lk.device.audio_route.changed', { + 'lk.device.audio_route.reason': 'new_device', + 'lk.device.audio_route.outputs': 'bluetooth', + }); + telemetry.pipeline.emit('lk.device.audio.interruption', { + 'lk.device.audio.interruption': 'began', + }); + telemetry.captureFailed(new DOMException('denied', 'NotAllowedError'), 'camera'); + + // hang up: the open windows ship, the session summary goes with the last upload + await publisher.disconnect(); + await subscriber.disconnect(); + media.stop(); + + // a connect the server refuses, and one the app cancels while it is in flight + await expect(new Room().connect(url, 'not-a-token')).rejects.toThrow(); + const aborted = new Room(); + const connecting = aborted.connect(url, subscriberToken); + await new Promise((resolve) => + aborted.once(RoomEvent.ConnectionStateChanged, () => resolve()), + ); + await aborted.disconnect(); + await connecting.catch(() => {}); + await telemetry.pipeline.flush(true); + + console.log( + `telemetry e2e: app.call_id=${marker} traces ${spans('lk.connect') + .map((s) => s.traceId) + .join(', ')}`, + ); + + // spans: two connects succeeded, one failed, one was cancelled + const outcomes = spans('lk.connect').map((s) => s.attributes['lk.outcome']); + expect(outcomes.filter((o) => o === 'ok')).toHaveLength(2); + expect(outcomes).toContain('error'); + expect(outcomes).toContain('cancelled'); + const failed = spans('lk.connect').find((s) => s.attributes['lk.outcome'] === 'error')!; + expect(failed.status).toBe(2); + expect(failed.attributes['error.type']).toBeTruthy(); + const connects = spans('lk.connect').filter((s) => s.attributes['lk.outcome'] === 'ok'); + for (const connect of connects) { + expect(connect.attributes).toMatchObject({ 'lk.outcome': 'ok', 'lk.connect.attempt': 1 }); + const names = connect.events.map((e) => e.name); + expect(names).toEqual(expect.arrayContaining(['pc_connected', 'room_connected'])); + // the required checkpoints, in SPEC's order + const required = ['ws_open', 'signal', 'join_recv', 'pc_created'].map((s) => + names.indexOf(s), + ); + expect(required.every((at, i) => at >= 0 && (i === 0 || at > required[i - 1]))).toBe(true); + } + // two publishes, both republished by the full reconnect + const publishes = spans('lk.publish'); + expect(publishes.length).toBeGreaterThanOrEqual(4); + expect(publishes.map((s) => s.attributes['lk.track.source'])).toEqual( + expect.arrayContaining(['camera', 'microphone']), + ); + for (const publish of publishes) { + expect(publish.attributes['lk.outcome']).toBe('ok'); + expect(publish.attributes['lk.track.sid']).toMatch(/^TR_/); + expect(publish.attributes['app.call_id']).toBe(marker); + } + for (const subscribe of okSubscribes()) { + expect(subscribe.events.map((e) => e.name)).toEqual(['subscribed', 'first_media']); + expect(subscribe.attributes['lk.participant.remote_identity']).toBe('publisher'); + } + // one span per cycle: a resume that turns into a restart is attempt 2 of the same span + const reconnects = spans('lk.reconnect'); + expect(reconnects).toHaveLength(2); + expect(reconnects.map((s) => s.attributes['lk.outcome'])).toEqual(['ok', 'ok']); + expect(reconnects[0].events[0].name).toBe('attempt 1 quick'); + expect(reconnects[0].attributes['lk.reconnect.attempts']).toBe(reconnects[0].events.length); + expect(reconnects[1].events.map((e) => e.name)).toEqual(['attempt 1 full']); + expect(reconnects[1].attributes['lk.reconnect.mode']).toBe('full'); + expect(reconnects[0].attributes['lk.reconnect.reason']).toBe('signal_disconnected'); + + // windows: both directions, both kinds, bytes flowing + const windows = events('lk.rtc.stats.sample'); + const directions = new Set(windows.map((w) => w.attributes['lk.track.direction'])); + const kinds = new Set(windows.map((w) => w.attributes['lk.track.kind'])); + expect(directions).toEqual(new Set(['inbound', 'outbound'])); + expect(kinds).toEqual(new Set(['audio', 'video'])); + expect(windows.some((w) => Number(w.attributes['lk.rtc.bytes']) > 0)).toBe(true); + + // events + const disconnects = events('lk.room.disconnected'); + const reasons = disconnects.map((d) => d.attributes['lk.disconnect.reason']); + expect(reasons.filter((r) => r === 'client_initiated').length).toBeGreaterThanOrEqual(2); + expect(reasons.length).toBeGreaterThanOrEqual(3); // the refused connect reports its own + expect(disconnects.some((d) => d.attributes['app.call_id'] === marker)).toBe(true); + expect(events('custom.e2e.checkpoint')[0].attributes).toMatchObject({ + step: 'reconnected', + 'app.call_id': marker, + 'lk.room.name': publisher.name, + }); + const warning = records.find( + (r): r is LogRecord => r.kind === 'log' && r.body === 'e2e: a warning for telemetry', + ); + expect(warning?.attributes).toMatchObject({ + 'lk.log.source': 'sdk', + 'lk.log.logger': 'livekit-room', + 'lk.room.name': publisher.name, + }); + for (const name of [ + 'lk.device.app_state.changed', + 'lk.device.network.changed', + 'lk.device.thermal.changed', + 'lk.device.low_power.changed', + 'lk.device.memory.changed', + 'lk.device.battery.changed', + 'lk.device.audio_route.changed', + 'lk.device.audio.interruption', + 'lk.device.capture.failed', + 'lk.telemetry.report', + ]) { + expect(events(name).length, name).toBeGreaterThanOrEqual(1); + } + expect(events('lk.device.capture.failed')[0].attributes).toMatchObject({ + 'lk.device.capture.device': 'camera', + 'lk.device.capture.reason': 'permission_denied', + }); + + // the collector took everything; the only losses are the two invalid app calls + const stats = telemetry.pipeline.stats(); + console.log(`telemetry e2e stats ${JSON.stringify(stats)}`); + expect(stats['uploads.sent']).toBeGreaterThanOrEqual(2); + expect(stats['uploads.failed']).toBeUndefined(); + expect(Object.keys(stats).filter((key) => key.startsWith('dropped.'))).toEqual([ + 'dropped.invalid', + ]); + expect(stats['dropped.invalid']).toBe(2); + expect(stats.cached).toBe(0); + + // opt-out: in effect when it returns, nothing more leaves + disableTelemetry(); + publisher.emitTelemetryEvent('after.opt.out'); + await telemetry.pipeline.flush(true); + expect(telemetry.pipeline.enabled).toBe(false); + expect(telemetry.pipeline.stats()['uploads.sent']).toBe(stats['uploads.sent']); + expect(records.some((r) => r.kind === 'log' && r.eventName === 'custom.after.opt.out')).toBe( + false, + ); + }, 120_000); +}); diff --git a/src/telemetry/telemetry.test.ts b/src/telemetry/telemetry.test.ts new file mode 100644 index 0000000000..e85957cb0b --- /dev/null +++ b/src/telemetry/telemetry.test.ts @@ -0,0 +1,1612 @@ +import { DisconnectReason, ReconnectReason } from '@livekit/protocol'; +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; +import { configureTelemetryHost, disableTelemetry, telemetry } from '.'; +import log, { LOG_OWNER, LogLevel, getLogger, setLogCapture, setLogLevel } from '../logger'; +import type { LogRecord, SpanRecord, TelemetryRecord } from './otlp'; +import { encode, mask, rejectedRecords } from './otlp'; +import { FLUSH_INTERVAL_MS, Pipeline } from './pipeline'; +import { StatsPoller } from './poller'; +import { TelemetryScope, TelemetrySpan, guarded } from './scope'; +import { + MemoryStorage, + type TelemetryStorage, + batchId, + decodeBatch, + encodeBatch, + parseBatchId, +} from './storage'; +import { + backoffMs, + classify, + cloudHost, + fingerprint, + parseRetryAfter, + readToken, +} from './transport'; +import { foldLayers, peerSamples } from './webrtc'; + +/** + * The JS-only paths of the pipeline: storage, token parsing, URL rules, the collector-answer table + * and the self-report, against a mock `fetch`. Spans, events and the browser session are covered + * end to end in `telemetry.browser.test.ts`. + */ + +const b64 = (value: object) => + btoa(JSON.stringify(value)).replace(/=+$/, '').replace(/\+/g, '-').replace(/\//g, '_'); +const jwt = (claims: object) => `${b64({ alg: 'HS256' })}.${b64(claims)}.sig`; +const future = Math.floor(Date.now() / 1000) + 600; +const granted = (extra: object = {}) => + jwt({ exp: future, observability: { write: true }, ...extra }); +const CLOUD = 'wss://proj-abc.livekit.cloud'; + +interface Call { + url: string; + headers: Record; + body: Uint8Array; +} + +function mockFetch( + answers: Array<{ status: number; headers?: Record; body?: BodyInit }>, +) { + const calls: Call[] = []; + const fetchMock = vi.fn(async (url: string, init: RequestInit) => { + if (init.signal?.aborted) throw new Error('aborted'); + const body = new Uint8Array(await new Response(init.body as BodyInit).arrayBuffer()); + calls.push({ url, headers: init.headers as Record, body }); + const answer = answers.shift() ?? { status: 200 }; + return new Response(answer.body ?? '', { status: answer.status, headers: answer.headers }); + }); + vi.stubGlobal('fetch', fetchMock); + return calls; +} + +function connectedScope(pipeline: Pipeline, token = granted(), url = CLOUD) { + const scope = new TelemetryScope(pipeline); + scope.setServer(url, token); + return scope; +} + +const sleep = (ms: number) => new Promise((resolve) => setTimeout(resolve, ms)); + +/** The strings inside a (gzipped) request body — protobuf keeps them verbatim. */ +async function textOf(call: Call) { + const encoding = call.headers['Content-Encoding']; + const stream = new Blob([call.body as BlobPart]).stream(); + const plain = encoding ? stream.pipeThrough(new DecompressionStream('gzip')) : stream; + return new TextDecoder().decode(await new Response(plain).arrayBuffer()); +} + +async function flushed(pipeline: Pipeline) { + await pipeline.flush(); + // a 413 split or a wake-up is served by the next pass + await pipeline.flush(); +} + +describe('transport rules', () => { + test('derives the ingest only from a Cloud host over TLS', () => { + expect(cloudHost('wss://proj.livekit.cloud')).toBe('proj.livekit.cloud'); + expect(cloudHost('https://proj.staging.livekit.cloud/')).toBe('proj.staging.livekit.cloud'); + expect(cloudHost('ws://proj.livekit.cloud')).toBeUndefined(); + expect(cloudHost('wss://proj.livekit.cloud:8443')).toBeUndefined(); + expect(cloudHost('wss://user@proj.livekit.cloud')).toBeUndefined(); + expect(cloudHost('wss://proj.livekit.cloud.evil.com')).toBeUndefined(); + expect(cloudHost('wss://localhost:7880')).toBeUndefined(); + expect(cloudHost('not a url')).toBeUndefined(); + }); + + test('reads the grant and exp off the token without verifying it', () => { + expect(readToken(granted())).toMatchObject({ granted: true, expired: false }); + expect(readToken(jwt({ observability: { clientWrite: true } }))).toMatchObject({ + granted: true, + expiresAt: undefined, + }); + expect(readToken(jwt({ exp: future, video: { roomJoin: true } })).granted).toBe(false); + expect(readToken(jwt({ exp: 1, observability: { write: true } })).expired).toBe(true); + expect(readToken(jwt({ exp: 'soon', observability: { write: true } })).expired).toBe(true); + expect(readToken('garbage')).toEqual({ granted: false, expired: true }); + }); + + test('classifies every collector answer the SPEC table names', () => { + expect(classify(200, null, '')).toEqual({ kind: 'accepted', rejected: 0 }); + expect(classify(400, null, '')).toEqual({ kind: 'rejected' }); + expect(classify(0, null, '')).toEqual({ kind: 'rejected' }); // an opaque redirect + expect(classify(413, null, '')).toEqual({ kind: 'oversized' }); + expect(classify(403, null, 'Project data recording is disabled by owner')).toEqual({ + kind: 'disabled', + }); + expect(classify(401, null, 'invalid token')).toEqual({ kind: 'unauthorized' }); + expect(classify(404, null, '')).toEqual({ kind: 'gone' }); + expect(classify(429, null, '')).toEqual({ kind: 'pause', forMs: 60_000 }); + expect(classify(429, '7', '')).toEqual({ kind: 'pause', forMs: 7_000 }); + expect(classify(503, '12', '')).toEqual({ kind: 'pause', forMs: 12_000 }); + expect(classify(503, null, '')).toEqual({ kind: 'retry' }); + expect(classify(502, null, '')).toEqual({ kind: 'retry' }); + expect(classify(500, null, '')).toEqual({ kind: 'rejected' }); + expect(classify(500, null, 'type.googleapis.com/google.rpc.RetryInfo')).toEqual({ + kind: 'retry', + }); + }); + + test('bounds Retry-After and the backoff', () => { + const now = Date.parse('2026-10-01T12:00:00Z'); + expect(parseRetryAfter('30', now)).toBe(30_000); + expect(parseRetryAfter('-5', now)).toBe(0); + expect(parseRetryAfter('Thu, 01 Oct 2026 12:00:10 GMT', now)).toBe(10_000); + expect(parseRetryAfter('garbage', now)).toBeUndefined(); + expect(parseRetryAfter(String(10 * 24 * 3600), now)).toBe(24 * 3600 * 1000); + for (const failures of [1, 3, 20]) { + const wait = backoffMs(failures); + expect(wait).toBeGreaterThanOrEqual(0); + expect(wait).toBeLessThanOrEqual(Math.min(60_000, 1000 * 2 ** (failures - 1))); + } + }); + test('a token fingerprint survives a 32-bit hash collision and keeps no token material', () => { + const fnv = (text: string) => { + let hash = 0x811c9dc5; + for (let i = 0; i < text.length; i += 1) { + hash = Math.imul(hash ^ text.charCodeAt(i), 0x01000193) >>> 0; + } + return hash; + }; + const seen = new Map(); + let pair: [string, string] | undefined; + for (let i = 0; i < 600_000 && !pair; i += 1) { + const text = Math.random().toString(36).slice(2, 12).padEnd(10, 'x'); // same length: only the hashes can differ + const other = seen.get(fnv(text)); + if (other !== undefined && other !== text) pair = [other, text]; + else seen.set(fnv(text), text); + } + expect(pair).toBeDefined(); // a birthday collision of the first hash + expect(fingerprint(pair![0])).not.toBe(fingerprint(pair![1])); + expect(fingerprint('eyJhbGciOi.eyJzdWIiOi.sig')).not.toContain('eyJ'); + }); +}); + +describe('storage', () => { + test('ids carry the batch metadata and sort oldest first', () => { + const id = batchId( + { timeMs: 1_700_000_000_000, records: 12, kind: 'traces', host: 'p.livekit.cloud' }, + 7, + ); + expect(parseBatchId(id)).toEqual({ + timeMs: 1_700_000_000_000, + records: 12, + kind: 'traces', + host: 'p.livekit.cloud', + }); + expect(parseBatchId(batchId({ timeMs: 1, records: 1, kind: 'logs', host: '' }, 1))?.host).toBe( + '', + ); + expect(parseBatchId('garbage')).toBeUndefined(); + const older = batchId({ timeMs: 1_000, records: 1, kind: 'logs', host: '' }, 2); + const newer = batchId({ timeMs: 2_000, records: 1, kind: 'logs', host: '' }, 1); + expect([newer, older].sort()).toEqual([older, newer]); + }); + + test('memory storage evicts the oldest by bytes and by count; a split replaces in one step or not at all', () => { + const storage = new MemoryStorage(10, 2); + expect(storage.put('a', new Uint8Array(4))).toEqual([]); + expect(storage.put('b', new Uint8Array(4))).toEqual([]); + expect(storage.put('c', new Uint8Array(4))).toEqual(['a']); // bytes: 12 > 10 + expect(storage.put('d', new Uint8Array(1))).toEqual(['b']); // count: 3 > 2 + expect(storage.put('e', new Uint8Array(9))).toEqual(['c']); // a lone batch within the bound stays + expect(storage.put('f', new Uint8Array(20))).toEqual(['d', 'e', 'f']); // one alone over the bytes goes too + expect(storage.pending()).toEqual([]); + const small = new MemoryStorage(10, 2); + small.put('p', new Uint8Array(6)); + const parts = (a: number, b: number): Array<[string, Uint8Array]> => [ + ['p1', new Uint8Array(a)], + ['p2', new Uint8Array(b)], + ]; + expect(small.replace('p', parts(3, 3))).toBe(true); + expect(small.pending()).toEqual(['p1', 'p2']); + expect(small.replace('p1', parts(1, 1))).toBe(false); // count 3 > 2: nothing changes + expect(small.pending()).toEqual(['p1', 'p2']); + }); + + test('a parseable body that is not a batch is corrupt', () => { + const text = (value: string) => new TextEncoder().encode(value); + expect(() => decodeBatch(text('{"not":"a batch"}'))).toThrow(); + expect(() => decodeBatch(text('[{"kind":"bogus","attributes":{}}]'))).toThrow(); + expect(() => decodeBatch(text('[1]'))).toThrow(); + expect(decodeBatch(encodeBatch([]))).toEqual([]); + }); +}); + +describe('OTLP encoding', () => { + test('writes a request the protobuf wire format can carry, and reads partial success back', () => { + const records: TelemetryRecord[] = [ + { + kind: 'log', + timeMs: 1_700_000_000_123, + severity: 'warn', + eventName: 'lk.ping', + body: 'lk.ping', + attributes: { 'lk.ping.seq': 1, flag: true, ratio: 0.5, name: 'x', skipped: undefined }, + traceId: '0123456789abcdef0123456789abcdef', + }, + { + kind: 'span', + name: 'lk.connect', + spanKind: 3, + traceId: '0123456789abcdef0123456789abcdef', + spanId: '0123456789abcdef', + startMs: 1_700_000_000_000, + endMs: 1_700_000_001_000, + status: 2, + statusMessage: 'boom', + attributes: { 'lk.outcome': 'error' }, + events: [{ name: 'ws_open', timeMs: 1_700_000_000_500 }], + }, + ]; + const bytes = encode(records, { 'service.name': 'livekit-client-js' }); + expect(bytes.byteLength).toBeGreaterThan(100); + // ResourceLogs(1) → ScopeLogs(2) → LogRecord(2) → event_name(12) is the last string of the first record + expect(new TextDecoder().decode(bytes)).toContain('lk.ping'); + expect(new TextDecoder().decode(bytes)).toContain('ws_open'); + // ExportLogsServiceResponse { partial_success { rejected_log_records: 300 } } + expect(rejectedRecords(Uint8Array.from([0x0a, 0x03, 0x08, 0xac, 0x02]))).toBe(300); + expect(rejectedRecords(new Uint8Array(0))).toBe(0); + // error_message (field 2) before rejected (field 1), and an unknown field ahead of partial_success + const reordered = [0x1a, 0x01, 0x78, 0x0a, 0x07, 0x12, 0x02, 0x68, 0x69, 0x08, 0xac, 0x02]; + expect(rejectedRecords(Uint8Array.from(reordered))).toBe(300); + }); +}); + +describe('stats mapping', () => { + const asReport = (stats: object[]) => + new Map(stats.map((s) => [(s as { id: string }).id, s])) as unknown as RTCStatsReport; + const outbound = new Map([['mst', { sid: 'TR', kind: 'video', direction: 'outbound' } as const]]); + const inbound = new Map([['mst', { sid: 'TR', kind: 'audio', direction: 'inbound' } as const]]); + + test('layers are read apart and folded as the core does; RTT and gauges keep their precision', () => { + const layer = (rid: string, bytesSent: number, cpu: number) => ({ + id: `o-${rid}`, + type: 'outbound-rtp', + trackIdentifier: 'mst', + rid, + bytesSent, + qualityLimitationDurations: { cpu, bandwidth: 0, other: 0 }, + }); + const two = peerSamples( + asReport([ + layer('h', 100, 1), + layer('q', 50, 1), + { id: 'ri', type: 'remote-inbound-rtp', localId: 'o-h', roundTripTime: 0.0425 }, + ]), + outbound, + ).get('TR')!; + expect(Array.from(two.layers.keys())).toEqual(['h', 'q']); + const folded = foldLayers(two.layers); + expect(folded.counters['lk.rtc.bytes']).toBe(150); // summed across layers + expect(folded.counters['lk.rtc.quality_limitation.cpu_ms']).toBe(1000); // per encoder: the maximum, not 2 s + expect(folded.gauges['lk.rtc.rtt_ms']).toBeCloseTo(42.5); // remote-inbound found by localId, unrounded + }); + + test('the pair RTT comes from the selected pair, else the nominated succeeded one; jitter is not rounded', () => { + const stream = { + id: 'in1', + type: 'inbound-rtp', + trackIdentifier: 'mst', + bytesReceived: 9, + jitter: 0.0123, + }; + const pair = { + id: 'cp1', + type: 'candidate-pair', + nominated: true, + state: 'succeeded', + currentRoundTripTime: 0.05, + }; + const nominated = foldLayers(peerSamples(asReport([stream, pair]), inbound).get('TR')!.layers); + expect(nominated.gauges['lk.rtc.rtt_ms']).toBeCloseTo(50); + expect(nominated.gauges['lk.rtc.jitter_ms']).toBeCloseTo(12.3); + const other = { + id: 'cp2', + type: 'candidate-pair', + nominated: true, + state: 'succeeded', + currentRoundTripTime: 0.2, + }; + const transport = { id: 't', type: 'transport', selectedCandidatePairId: 'cp2' }; + const selected = foldLayers( + peerSamples(asReport([stream, pair, other, transport]), inbound).get('TR')!.layers, + ); + expect(selected.gauges['lk.rtc.rtt_ms']).toBeCloseTo(200); + }); +}); + +describe('pipeline', () => { + let pipeline: Pipeline; + + beforeEach(() => { + vi.useFakeTimers(); + pipeline = new Pipeline(); + }); + + afterEach(() => { + vi.unstubAllGlobals(); + vi.useRealTimers(); + }); + + test('sends a Room’s records to its project with its token, and nothing without the grant', async () => { + const calls = mockFetch([{ status: 200 }, { status: 200 }]); + const scope = connectedScope(pipeline); + scope.emit('custom.one'); + scope.start('lk.publish').end('ok'); + const ungranted = connectedScope(pipeline, jwt({ exp: future }), 'wss://other.livekit.cloud'); + ungranted.emit('custom.never'); + // The first token decides: a later grant does not opt the project in (SPEC). + ungranted.refreshToken(granted({ jti: 'late' })); + ungranted.emit('custom.never.either'); + await flushed(pipeline); + expect(calls.map((c) => c.url).sort()).toEqual([ + 'https://proj-abc.livekit.cloud/observability/client/logs/otlp/v0', + 'https://proj-abc.livekit.cloud/observability/client/traces/otlp/v0', + ]); + expect(calls[0].headers.Authorization).toBe(`Bearer ${granted()}`); + expect(calls[0].headers.Priority).toBe('u=7'); + expect(pipeline.stats()).toMatchObject({ 'uploads.sent': 2, cached: 0, queued: 0 }); + }); + + test('a non-Cloud server collects nothing; the collector override sends everything there', async () => { + const calls = mockFetch([]); + connectedScope(pipeline, granted(), 'ws://localhost:7880').emit('custom.local'); + await flushed(pipeline); + expect(calls).toHaveLength(0); + pipeline.endpoint = 'http://127.0.0.1:4318/'; + connectedScope(pipeline, 'no-token', 'ws://localhost:7880').emit('custom.local'); + await flushed(pipeline); + expect(calls[0].url).toBe('http://127.0.0.1:4318/v1/logs'); + expect(calls[0].headers.Authorization).toBeUndefined(); + }); + + test('a refreshed token replaces the one in use; an expired or refused one holds the batch', async () => { + const calls = mockFetch([{ status: 401, body: 'invalid token' }, { status: 200 }]); + const scope = connectedScope(pipeline); + scope.emit('custom.one'); + await flushed(pipeline); + expect(calls).toHaveLength(1); + expect(pipeline.stats()).toMatchObject({ 'uploads.unauthorized': 1, cached: 1 }); + await flushed(pipeline); + expect(calls).toHaveLength(1); // the refused token is never sent again + scope.refreshToken(jwt({ exp: 1, observability: { write: true } })); + await flushed(pipeline); + expect(calls).toHaveLength(1); // an expired one is not sent either + const fresh = granted({ jti: 'fresh' }); + scope.refreshToken(fresh); + await flushed(pipeline); + expect(calls).toHaveLength(2); + expect(calls[1].headers.Authorization).toBe(`Bearer ${fresh}`); + }); + + test('each answer in the table has its consequence', async () => { + const calls = mockFetch([ + { status: 429, headers: { 'Retry-After': '30' } }, + { status: 503 }, + { status: 400 }, + // ExportLogsServiceResponse { partial_success { rejected_log_records: 1 } } + { status: 200, body: Uint8Array.from([0x0a, 0x02, 0x08, 0x01]) }, + ]); + const scope = connectedScope(pipeline); + scope.emit('custom.a'); + await flushed(pipeline); // 429: kept, paused 30 s + expect(pipeline.stats()).toMatchObject({ 'uploads.failed': 1, cached: 1 }); + await flushed(pipeline); + expect(calls).toHaveLength(1); + vi.advanceTimersByTime(30_001); + await flushed(pipeline); // 503 without a delay: kept, local backoff + expect(calls).toHaveLength(2); + expect(pipeline.stats()).toMatchObject({ 'uploads.failed': 2, cached: 1 }); + vi.advanceTimersByTime(60_001); + await flushed(pipeline); // 400: dropped and counted + expect(pipeline.stats()).toMatchObject({ 'dropped.rejected': 1, cached: 0 }); + scope.emit('custom.b'); + scope.emit('custom.c'); + await flushed(pipeline); // 2xx with partial success: removed, the rejected record counted + expect(pipeline.stats()).toMatchObject({ 'uploads.sent': 1, 'dropped.rejected': 2, cached: 0 }); + }); + + test('404 silences the project until its next token; the owner’s opt-out silences it for good', async () => { + const calls = mockFetch([ + { status: 404 }, + { status: 200 }, + { status: 403, body: 'project data recording is disabled by owner' }, + ]); + const scope = connectedScope(pipeline); + scope.emit('custom.a'); + scope.emit('custom.b'); + await flushed(pipeline); + expect(pipeline.stats().cached).toBe(0); // purged with the project + scope.emit('custom.c'); + await flushed(pipeline); + expect(calls).toHaveLength(1); // silent + scope.refreshToken(granted({ jti: 'next' })); + await flushed(pipeline); + expect(calls).toHaveLength(2); // the next token revives it + scope.emit('custom.d'); + await flushed(pipeline); + scope.refreshToken(granted({ jti: 'another' })); + scope.emit('custom.e'); + await flushed(pipeline); + expect(calls).toHaveLength(3); + expect(pipeline.stats().cached).toBe(0); + }); + + test('413 splits the batch down to the record, and a lone oversized record is dropped', async () => { + const calls = mockFetch([{ status: 413 }, { status: 200 }, { status: 413 }]); + const scope = connectedScope(pipeline); + for (const name of ['a', 'b', 'c']) scope.emit(`custom.${name}`); + await flushed(pipeline); + // [a b c] → 413 → [a b] accepted, [c] → 413 → a lone record is oversized + expect(calls).toHaveLength(3); + expect(pipeline.stats()).toMatchObject({ + 'uploads.sent': 1, + 'dropped.oversized': 1, + cached: 0, + }); + }); + + /** A one-slot store that throws on its n-th write: the disk is full and then refuses. */ + function flakyStore(throwOnPut: number, slots = 1) { + const storage = new MemoryStorage(1 << 20, slots); + let puts = 0; + const put = storage.put.bind(storage); + storage.put = (id, body) => { + puts += 1; + if (puts === throwOnPut) throw new Error('disk full'); + return put(id, body); + }; + return storage; + } + + test('a 413 split takes the parent’s place in one step, or leaves the parent whole: nothing evicted in between', async () => { + const calls = mockFetch([{ status: 413 }, { status: 413 }, { status: 200 }, { status: 200 }]); + // one slot: the halves cannot fit, the parent stays whole and waits for the backoff + pipeline.storage = new MemoryStorage(1 << 20, 1); + const scope = connectedScope(pipeline); + for (const name of ['a', 'b']) scope.emit(`custom.${name}`); + await pipeline.flush(); + expect(calls).toHaveLength(1); + expect(pipeline.storage.pending()).toHaveLength(1); + expect(parseBatchId(pipeline.storage.pending()[0])?.records).toBe(2); + expect(Object.keys(pipeline.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + expect(pipeline.stats()['uploads.failed']).toBe(1); + // two slots: both halves replace the parent and ship + const two = new Pipeline(); + two.storage = new MemoryStorage(1 << 20, 2); + const other = connectedScope(two); + for (const name of ['c', 'd']) other.emit(`custom.${name}`); + await flushed(two); + expect(two.stats()).toMatchObject({ 'uploads.sent': 2, cached: 0 }); + expect(Object.keys(two.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + }); + + test('a host store without `replace` never splits: the parent stays whole and waits for the backoff', async () => { + const bare = (slots: number): TelemetryStorage => { + const memory = new MemoryStorage(1 << 20, slots); + return { + put: (id, body) => memory.put(id, body), + pending: () => memory.pending(), + read: (id) => memory.read(id), + remove: (id) => memory.remove(id), + clear: () => memory.clear(), + }; + }; + mockFetch([{ status: 413 }, { status: 413 }]); + for (const slots of [1, 2]) { + const one = new Pipeline(); + one.storage = bare(slots); + const scope = connectedScope(one); + for (const name of ['a', 'b']) scope.emit(`custom.${name}`); + await one.flush(); + expect(one.storage.pending()).toHaveLength(1); + expect(parseBatchId(one.storage.pending()[0])?.records).toBe(2); + expect(Object.keys(one.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + expect(one.stats()['uploads.failed']).toBe(1); + } + }); + + test('a batch the store will not delete is never sent again', async () => { + const calls = mockFetch([{ status: 200 }, { status: 200 }]); + const store = new MemoryStorage(1 << 20, 10); + let refuse = true; + const remove = store.remove.bind(store); + store.remove = (id) => { + if (refuse) throw new Error('locked'); + remove(id); + }; + pipeline.storage = store; + const scope = connectedScope(pipeline); + scope.emit('custom.once'); + await pipeline.flush(); // taken by the collector, deletion refused + expect(calls).toHaveLength(1); + expect(pipeline.stats()).toMatchObject({ + 'uploads.sent': 1, + 'cache.delete_errors': 1, + cached: 1, + }); + await pipeline.flush(); // still there, never re-sent + expect(calls).toHaveLength(1); + refuse = false; + await pipeline.flush(); + expect(calls).toHaveLength(1); + expect(pipeline.stats().cached).toBe(0); + }); + + test('a batch the store cannot read right now is kept for the next pass, never deleted', async () => { + const calls = mockFetch([{ status: 200 }]); + const store = new MemoryStorage(1 << 20, 10); + let locked = true; + const read = store.read.bind(store); + store.read = (id) => { + if (locked) throw new Error('file locked'); + return read(id); + }; + pipeline.storage = store; + const scope = connectedScope(pipeline); + scope.emit('custom.kept'); + await pipeline.flush(); + expect(calls).toHaveLength(0); + expect(pipeline.stats()).toMatchObject({ 'cache.read_errors': 1, cached: 1 }); + locked = false; + await pipeline.flush(); + expect(calls).toHaveLength(1); + expect(pipeline.stats()).toMatchObject({ 'uploads.sent': 1, cached: 0 }); + expect(Object.keys(pipeline.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + }); + + test('a split with no fallback left keeps the parent whole, every record exactly once', async () => { + mockFetch([{ status: 413 }]); + const storage = flakyStore(3); + pipeline.storage = storage; + (pipeline as unknown as { cache: TelemetryStorage }).cache = storage; // the raw store, no fallback + const scope = connectedScope(pipeline); + for (const name of ['a', 'b']) scope.emit(`custom.${name}`); + await pipeline.flush(); // one pass: the 413, the first half evicts the parent, the second half fails + expect(storage.pending()).toHaveLength(1); + expect(parseBatchId(storage.pending()[0])?.records).toBe(2); // the parent, re-stored + expect(Object.keys(pipeline.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + }); + + test('a store the disk refuses is kept in memory, counted as a write error, and still uploaded', async () => { + const calls = mockFetch([{ status: 200 }]); + const refusing = new MemoryStorage(1 << 20, 10); + refusing.put = () => { + throw new Error('disk gone'); + }; + pipeline.storage = refusing; + const scope = connectedScope(pipeline); + scope.emit('custom.kept'); + await flushed(pipeline); + expect(calls).toHaveLength(1); + expect(pipeline.stats()).toMatchObject({ + 'uploads.sent': 1, + 'cache.write_errors': 1, + cached: 0, + }); + expect(Object.keys(pipeline.stats()).filter((k) => k.startsWith('dropped.'))).toEqual([]); + }); + + test('the collector override never carries a bearer, cached Cloud batches included', async () => { + const calls = mockFetch([{ status: 503, headers: { 'Retry-After': '60' } }]); + const scope = connectedScope(pipeline); + scope.emit('custom.cloud'); + await pipeline.flush(); // 503: the batch stays cached, the project's token is known + expect(calls[0].headers.Authorization).toBeDefined(); + pipeline.endpoint = 'http://collector.test'; + await flushed(pipeline); + const toCollector = calls.slice(1); + expect(toCollector.length).toBeGreaterThanOrEqual(1); + for (const call of toCollector) { + expect(call.url).toMatch(/^http:\/\/collector\.test\/v1\//); + expect(call.headers.Authorization).toBeUndefined(); + } + }); + + test('a refused token is never sent again before it expires, one without exp never in the process, all gone at opt-out', async () => { + const calls = mockFetch(Array.from({ length: 60 }, () => ({ status: 401 }))); + const scope = connectedScope(pipeline); + scope.inCall = false; // no per-interval budget: every pass sends until the token is refused + const refresh = (token: string) => pipeline.setServer(CLOUD, token, scope); + const peek = () => + (pipeline as unknown as { projects: Map }> }).projects; + const tokens = Array.from({ length: 40 }, (_, i) => granted({ jti: String(i) })); + for (const token of tokens) { + refresh(token); + scope.emit('custom.x'); + await pipeline.flush(); + } + const refused = peek().get('proj-abc.livekit.cloud')!.refused; + expect(refused.size).toBe(40); // nothing forgotten to make room + for (const key of Array.from(refused.keys())) expect(key).not.toContain('eyJ'); // never the token + const sent = calls.length; + refresh(tokens[0]); + scope.emit('custom.again'); + await pipeline.flush(); + expect(calls).toHaveLength(sent); // the first refused token never goes out again + const forever = jwt({ observability: { write: true }, jti: 'forever' }); // no exp + refresh(forever); + scope.emit('custom.f'); + await pipeline.flush(); + expect(calls).toHaveLength(sent + 1); + vi.setSystemTime(Date.now() + 365 * 24 * 3600 * 1000); + refresh(forever); + scope.emit('custom.g'); + await pipeline.flush(); + expect(calls).toHaveLength(sent + 1); // still refused a year later + expect(refused.size).toBe(1); // the expired ones are reaped, the one without exp stays + pipeline.disable(); + expect(peek().size).toBe(0); + }); + + test('a hold or a 5xx keeps caching; the self-report carries deltas and the opt-out purges', async () => { + const calls = mockFetch([{ status: 502 }, { status: 200 }, { status: 200 }]); + const scope = connectedScope(pipeline); + scope.connectStarted(CLOUD, granted()); + scope.emit('custom.held'); + await flushed(pipeline); + expect(calls).toHaveLength(0); // held while `lk.connect` is open … + expect(pipeline.stats().cached).toBe(1); // … but cached, write-ahead + scope.connectEnded('ok'); + await flushed(pipeline); + expect(calls).toHaveLength(1); // 502: failed, kept + vi.advanceTimersByTime(FLUSH_INTERVAL_MS); + await flushed(pipeline); + expect(calls).toHaveLength(3); // the backoff is over: the logs batch and the span batch go out + let report: TelemetryRecord | undefined; + pipeline.onBatch = (records) => { + report ??= records.find((r) => r.kind === 'log' && r.eventName === 'lk.telemetry.report'); + }; + await pipeline.flush(true); // the session summary: a batch of its own only at a forced flush + expect(calls).toHaveLength(4); + expect(report?.attributes).toMatchObject({ + 'lk.telemetry.uploads.failed': 1, + 'lk.telemetry.uploads.sent': 2, + 'lk.telemetry.cache.batches': 0, + }); + scope.emit('custom.after'); + pipeline.disable(); + await flushed(pipeline); + expect(pipeline.enabled).toBe(false); + expect(pipeline.stats()).toMatchObject({ cached: 0, queued: 0 }); + expect(calls).toHaveLength(4); + }); + + test('a stalled request is abandoned after the export timeout and the batch kept', async () => { + vi.stubGlobal( + 'fetch', + vi.fn( + (_url: string, init: RequestInit) => + new Promise((_, reject) => { + if (init.signal?.aborted) reject(new Error('aborted')); + init.signal?.addEventListener('abort', () => reject(new Error('aborted'))); + }), + ), + ); + const scope = connectedScope(pipeline); + scope.emit('custom.slow'); + const flush = pipeline.flush(); + await vi.advanceTimersByTimeAsync(10_001); + await flush; + expect(pipeline.stats()).toMatchObject({ + 'uploads.timeouts': 1, + 'uploads.failed': 1, + cached: 1, + }); + }); + + test('custom events and attributes are validated, never truncated', async () => { + const records: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => records.push(...batch); + const scope = connectedScope(pipeline); + scope.setAttribute('app.call_id', 'c-1'); + scope.setAttribute('lk.room.sid', 'spoof'); + scope.setAttribute('session.id', 'spoof'); + scope.setAttribute('long', 'x'.repeat(1025)); + scope.emitCustom('checkout', { step: 'pay' }); + scope.emitCustom('', {}); + scope.emitCustom('bad', { 'lk.secret': 'x' }); + scope.setAttribute('app.call_id', null); + scope.emitCustom('after'); + await pipeline.flush(); + const events = records.map((r) => (r as { eventName?: string }).eventName ?? ''); + expect(events.filter((name) => name.startsWith('custom.'))).toEqual([ + 'custom.checkout', + 'custom.after', + ]); + expect(events).toContain('lk.telemetry.report'); // rides in the same batch, never its own + expect(records[0].attributes['app.call_id']).toBe('c-1'); + expect(records[0].attributes['lk.room.sid']).toBeUndefined(); + expect(records[1].attributes['app.call_id']).toBeUndefined(); + expect(pipeline.stats()['dropped.invalid']).toBe(5); + }); + + test('a failing scope never throws into the caller', () => { + const scope = guarded(new TelemetryScope(pipeline)); + vi.spyOn(pipeline, 'record').mockImplementation(() => { + throw new Error('telemetry is broken'); + }); + expect(() => { + scope.connectStarted(CLOUD, granted()); + scope.emit('custom.x'); + scope.start('lk.publish').end('ok'); + scope.subscribeStarted({ sid: 'TR_1', kind: 'audio' }); + scope.disconnected(); + }).not.toThrow(); + }); + + test('SDK warnings reach the capture whatever the console level', () => { + const captured: Array<[LogLevel, unknown, string | undefined]> = []; + setLogCapture((level, msg, _context, name) => captured.push([level, msg, name])); + const logger = getLogger('livekit-telemetry-test'); + setLogLevel('silent', undefined); + logger.setLevel('silent'); + logger.warn(`token ${granted()} leaked`); + logger.error('boom'); + logger.info('quiet'); + setLogCapture(undefined); + logger.warn('after'); + expect(captured.map(([level]) => level)).toEqual([LogLevel.warn, LogLevel.error]); + expect(captured[0][2]).toBe('livekit-telemetry-test'); + expect(String(captured[0][1])).toContain(granted()); // raw here; masked by the pipeline + }); + + test('tokens are masked in log bodies and span statuses', async () => { + expect(mask(`Authorization: Bearer ${granted()} and bearer abc.def-ghi`)).toBe( + 'Authorization: Bearer and bearer ', + ); + const records: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => records.push(...batch); + const scope = connectedScope(pipeline); + scope.start('lk.publish').fail(new Error(`refused: ${granted()}`)); + await pipeline.flush(); + expect((records[0] as { statusMessage?: string }).statusMessage).toBe('refused: '); + // the SDK logger path, through the installed pipeline + const installed = telemetry.pipeline; + const seen: TelemetryRecord[] = []; + installed.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const room = telemetry.scope(); // installs the pipeline (and the log capture) + installed.endpoint = 'http://127.0.0.1:1'; + room.setServer('ws://localhost:7880', 'no-token'); + room.setRoom({ sid: 'RM', name: 'masked' }); + const ownLogger = getLogger('livekit-room', () => ({ room: 'masked', [LOG_OWNER]: room })); + ownLogger.warn(`token ${granted()} leaked`); + await installed.flush(); + const line = seen.find((r) => r.kind === 'log' && r.body?.startsWith('token ')); + expect(line?.body).toBe('token leaked'); + expect(line?.attributes['lk.room.name']).toBe('masked'); + }); + + test('a Room reused for another project ships nothing of the first project there', async () => { + vi.useRealTimers(); + let release!: () => void; + const held = new Promise((resolve) => { + release = resolve; + }); + const calls: Call[] = []; + vi.stubGlobal( + 'fetch', + vi.fn(async (url: string, init: RequestInit) => { + const body = new Uint8Array(await new Response(init.body as BodyInit).arrayBuffer()); + calls.push({ url, headers: init.headers as Record, body }); + if (calls.length === 1) await held; + return new Response('', { status: 200 }); + }), + ); + const tokenA = granted({ jti: 'a' }); + const tokenB = granted({ jti: 'b' }); + const scope = new TelemetryScope(pipeline); + scope.connectStarted('wss://proj-a.livekit.cloud', tokenA); + scope.connectEnded('ok'); + scope.emit('custom.first'); + const inFlight = pipeline.flush(); // request 1 to proj-a, held on the wire + await vi.waitFor(() => expect(calls).toHaveLength(1)); + scope.emit('custom.captured_under_a'); + scope.disconnected(DisconnectReason.CLIENT_INITIATED); // its flush waits behind the request + scope.connectStarted('wss://proj-b.livekit.cloud', tokenB); + scope.connectEnded('ok'); + release(); + await inFlight; + await flushed(pipeline); + await flushed(pipeline); + const toA = calls.filter((c) => c.url.startsWith('https://proj-a.livekit.cloud/')); + const toB = calls.filter((c) => c.url.startsWith('https://proj-b.livekit.cloud/')); + expect(toA.length).toBeGreaterThanOrEqual(2); + expect(toB.length).toBeGreaterThanOrEqual(1); + expect(toA.every((c) => c.headers.Authorization === `Bearer ${tokenA}`)).toBe(true); + expect(toB.every((c) => c.headers.Authorization === `Bearer ${tokenB}`)).toBe(true); + const textA = (await Promise.all(toA.map(textOf))).join('\n'); + const textB = (await Promise.all(toB.map(textOf))).join('\n'); + for (const name of ['custom.first', 'custom.captured_under_a', 'lk.room.disconnected']) { + expect(textA, name).toContain(name); + expect(textB, name).not.toContain(name); + } + expect(pipeline.stats().cached).toBe(0); + }); + + test('no getStats follows the opt-out, even mid-poll', async () => { + vi.useRealTimers(); + const reads: string[] = []; + const peer = (name: string) => ({ + getStats: () => { + reads.push(name); + return new Promise((resolve) => + setTimeout(() => resolve(new Map() as unknown as RTCStatsReport), 300), + ); + }, + }); + const scope = connectedScope(pipeline); + vi.spyOn(scope, 'statsPollIntervalMs').mockReturnValue(5); + const poller = new StatsPoller(scope, pipeline, { + peers: () => [peer('publisher'), peer('subscriber')], + tracks: () => new Map(), + }); + poller.start(); + await vi.waitFor(() => expect(reads).toEqual(['publisher'])); + pipeline.disable(); // lands while the first read is on the wire + await sleep(500); + expect(reads).toEqual(['publisher']); + }); + + test('a warning goes to the Room whose logger carried it, by identity; a Room-shaped context with no scope is dropped and counted', async () => { + telemetry.pipeline.endpoint = undefined; + const seen: TelemetryRecord[] = []; + telemetry.pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const cloud = telemetry.scope(); + cloud.setServer(CLOUD, granted()); + const selfHosted = telemetry.scope(); + selfHosted.setServer('ws://localhost:7880', 'no-token'); + // the Room's own logger, before the join: an empty identity, and the scope riding the context + const ownedBy = (scope: TelemetryScope) => + getLogger('livekit-room', () => ({ room: '', roomID: undefined, [LOG_OWNER]: scope })); + const plain = getLogger('livekit-room'); + plain.setLevel('silent'); + const before = telemetry.pipeline.stats()['dropped.unattributed'] ?? 0; + const policy = telemetry.pipeline.stats()['policy.no_ingest'] ?? 0; + // the console and log extensions see the context as before: the scope is not enumerable + const contexts: object[] = []; + const probe = getLogger('livekit-ctx-probe'); + probe.methodFactory = + () => + (...args: unknown[]) => { + if (args[1]) contexts.push(args[1] as object); + }; + probe.setLevel('warn'); + getLogger('livekit-ctx-probe', () => ({ + room: '', + roomID: undefined, + [LOG_OWNER]: cloud, + })).warn('visible context unchanged'); + expect(Object.keys(contexts[0])).toEqual(['room', 'roomID']); + expect(Object.getOwnPropertyDescriptor(contexts[0], LOG_OWNER)?.enumerable).toBe(false); + ownedBy(cloud).warn('for the cloud room'); + const weak = telemetry.carrier(cloud); + expect(weak).toBeInstanceOf(WeakRef); + getLogger('livekit-room', () => ({ room: '', [LOG_OWNER]: weak })).warn('via the weak carrier'); + ownedBy(selfHosted).warn('from the self-hosted room'); // its Room's, which has no ingest + plain.warn('room-shaped, nobody’s', { room: '', roomID: undefined }); + plain.warn('for the process'); + await telemetry.pipeline.flush(); + const bodies = seen.filter((r): r is LogRecord => r.kind === 'log' && !r.eventName); + expect(bodies.find((r) => r.body === 'for the cloud room')?.attributes['session.id']).toBe( + cloud.traceId, + ); + expect(bodies.find((r) => r.body === 'via the weak carrier')?.attributes['session.id']).toBe( + cloud.traceId, + ); + expect(bodies.find((r) => r.body === 'from the self-hosted room')).toBeUndefined(); + expect(telemetry.pipeline.stats()['policy.no_ingest']).toBe(policy + 1); + expect(bodies.find((r) => r.body?.startsWith('room-shaped'))).toBeUndefined(); + expect(telemetry.pipeline.stats()['dropped.unattributed']).toBe(before + 1); + expect(bodies.find((r) => r.body === 'for the process')?.attributes['session.id']).toBe( + telemetry.pipeline.processTraceId, + ); + telemetry.pipeline.onBatch = undefined; + }); + + test('a record keeps its capture-time collection decision, whatever the Room connects to next', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + scope.connectStarted('ws://localhost:7880', 'no-token'); // self-hosted: nothing of it is ever sent + scope.connectEnded('ok'); + const selfHosted = scope.start('lk.publish'); + scope.connectStarted('wss://proj-b.livekit.cloud', granted()); // reused for a Cloud project + scope.connectEnded('ok'); + const cloud = scope.start('lk.publish'); + scope.connectStarted('ws://localhost:7881', 'no-token'); // and self-hosted again + scope.connectEnded('ok'); + selfHosted.end('ok'); // never adopted by the Cloud project it never had + cloud.end('ok'); // never dropped because the Room is self-hosted now + await flushed(pipeline); + const publishes = seen.filter( + (r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.publish', + ); + expect(publishes.map((p) => p.spanId)).toEqual([cloud.spanId]); + expect(publishes[0].host).toBe('proj-b.livekit.cloud'); + expect(pipeline.stats()['policy.no_ingest']).toBeGreaterThanOrEqual(1); // counted, never silent + expect(pipeline.stats()['dropped.unattributed']).toBeUndefined(); + }); + + test('telemetry holds a Room strongly only while it is in a call', () => { + const scope = new TelemetryScope(pipeline); + expect(pipeline.scopes.has(scope)).toBe(false); // constructed, never connected: tracked weakly only + scope.setServer(CLOUD, granted()); + expect(pipeline.scopes.has(scope)).toBe(true); + scope.disconnected(DisconnectReason.CLIENT_INITIATED); + expect(pipeline.scopes.has(scope)).toBe(false); + }); + + test('a span or window opened under one connection keeps that owner through the next', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + scope.connectStarted('wss://proj-a.livekit.cloud', granted({ jti: 'a' })); + scope.connectEnded('ok'); + scope.setRoom({ sid: 'RA' }); + const span = scope.start('lk.publish'); + const report = new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst1', bytesReceived: 777 }], + ]) as unknown as RTCStatsReport; + const tracks = new Map([ + ['mst1', { sid: 'TR_A', kind: 'audio', direction: 'inbound' } as const], + ]); + scope.recordPeerStats(report, tracks); // a window opens under A + scope.connectStarted('wss://proj-b.livekit.cloud', granted({ jti: 'b' })); + scope.connectEnded('ok'); + scope.setRoom({ sid: 'RB' }); + span.end('ok'); + scope.closeWindows(); + await flushed(pipeline); + const publish = seen.find((r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.publish'); + const window = seen.find( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + for (const record of [publish, window]) { + expect(record?.host).toBe('proj-a.livekit.cloud'); + expect(record?.attributes['lk.room.sid']).toBe('RA'); + } + expect(window?.attributes['lk.rtc.bytes']).toBe(777); + }); + + test('an old poll never reads or records under a later connection, whichever peer answers', async () => { + vi.useRealTimers(); + const reads: Array<{ peer: string; resolve: (report: RTCStatsReport) => void }> = []; + const peer = (name: string) => ({ + getStats: () => + new Promise((resolve) => { + reads.push({ peer: name, resolve }); + }), + }); + let trackCalls = 0; + const scope = connectedScope(pipeline); + const recorded = vi.spyOn(scope, 'recordPeerStats'); + vi.spyOn(scope, 'statsPollIntervalMs').mockReturnValue(5); + const poller = new StatsPoller(scope, pipeline, { + peers: () => [peer('publisher'), peer('subscriber')], + tracks: () => { + trackCalls += 1; + return new Map([ + ['mst', { sid: `T${trackCalls}`, kind: 'audio', direction: 'inbound' } as const], + ]); + }, + }); + const empty = () => new Map() as unknown as RTCStatsReport; + poller.start(); + await vi.waitFor(() => expect(reads).toHaveLength(1)); // the old poll's publisher read + poller.stop(); + poller.start(); + reads[0].resolve(empty()); // answers late: dropped, and the old poll reads no further peer + await sleep(20); + expect(recorded).not.toHaveBeenCalled(); + await vi.waitFor(() => expect(reads).toHaveLength(2)); // the new poll's publisher read + reads[1].resolve(empty()); + await vi.waitFor(() => expect(reads).toHaveLength(3)); // then its subscriber read + reads[2].resolve(empty()); + await vi.waitFor(() => expect(recorded).toHaveBeenCalledTimes(2)); + poller.stop(); // the next scheduled poll would add a fourth read + expect(reads.slice(0, 3).map((r) => r.peer)).toEqual(['publisher', 'publisher', 'subscriber']); + for (const call of recorded.mock.calls) expect(call[1].get('mst')?.sid).toBe('T2'); // the new track map, never the old + }); + + test('after the opt-out nothing is retained: no span buffer, attribute, identity, credential or timer', () => { + mockFetch([]); + const unconnected = new TelemetryScope(pipeline); // a Room that never connected + const preSpan = unconnected.start('lk.publish'); + const scope = connectedScope(pipeline); + scope.setRoom({ sid: 'RA', name: 'room' }); + scope.setAttribute('app.before', 'kept?'); + const span = scope.start('lk.publish', { attributes: { 'lk.track.kind': 'audio' } }); + span.step('early'); + const peek = () => (pipeline as unknown as { projects: Map }).projects; + expect(peek().size).toBe(1); + pipeline.disable(); + // purged: spans closed and emptied, identity, attributes and credentials gone + expect(preSpan.ended).toBe(true); // although its Room never had a server + expect(span.ended).toBe(true); + const buffers = span as unknown as { + events: unknown[]; + attributes: object; + owner: { attributes: object }; + }; + expect(buffers.events).toEqual([]); + expect(buffers.attributes).toEqual({}); + expect(buffers.owner.attributes).toEqual({}); + expect(scope.identity).toEqual({}); + expect(scope.host).toBeUndefined(); + expect(scope.attributes()['app.before']).toBeUndefined(); + expect(peek().size).toBe(0); + // refused afterwards: nothing is taken, nothing starts + scope.setServer(CLOUD, granted()); + scope.refreshToken(granted()); + pipeline.setServer(CLOUD, granted(), scope); + scope.setRoom({ sid: 'RB' }); + scope.trackPublished('TR_pub'); + scope.setAttribute('app.after', 'v'); + expect(peek().size).toBe(0); + expect(scope.host).toBeUndefined(); + expect(scope.identity).toEqual({}); + expect(scope.statsPollIntervalMs()).toBe(pipeline.statsWindowMs / 2); + expect(scope.attributes()['app.after']).toBeUndefined(); + span.step('late'); + span.end('ok'); + const timers = vi.getTimerCount(); + scope.subscribeStarted({ sid: 'TR_1', kind: 'video' }); + scope.subscribed({ sid: 'TR_2', kind: 'audio' }); + expect(vi.getTimerCount()).toBe(timers); + expect(scope.start('lk.publish').ended).toBe(true); + expect(pipeline.stats()).toMatchObject({ queued: 0, cached: 0 }); + }); + + test('a subscribe without media times out after 30 s on the pipeline’s clock', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = connectedScope(pipeline); + scope.subscribeStarted({ sid: 'TR_1', kind: 'video' }); + vi.advanceTimersByTime(30_000); + await pipeline.flush(); + const span = seen.find((r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.subscribe'); + expect(span?.attributes).toMatchObject({ 'lk.outcome': 'error', 'error.type': 'timed_out' }); + expect(span?.status).toBe(2); + }); + + test('the logger passes every argument through unchanged, with or without the capture', () => { + const logger = getLogger('livekit-telemetry-args'); + const seen: unknown[][] = []; + logger.methodFactory = + () => + (...args: unknown[]) => { + seen.push(args); + }; + logger.setLevel('warn'); // rebuilds the methods; the forwarder wraps the recorder + setLogCapture(undefined); + logger.warn('m', 0, 'third'); + const captured: unknown[] = []; + setLogCapture((_level, msg, context) => captured.push(msg, context)); + logger.warn('m', 0, 'third'); + logger.error('e', { a: 1 }); + setLogCapture(undefined); + expect(seen).toEqual([ + ['m', 0, 'third'], + ['m', 0, 'third'], + ['e', { a: 1 }], + ]); + expect(captured).toEqual(['m', undefined, 'e', { a: 1 }]); + }); + + test('a throwing log extension never turns a telemetry failure into an SDK exception', () => { + const debug = log.debug; + log.debug = () => { + throw new Error('log extension down'); + }; + try { + const failing = guarded({ + run() { + throw new Error('telemetry bug'); + }, + }); + expect(() => failing.run()).not.toThrow(); + } finally { + log.debug = debug; + } + }); + + test('required connect checkpoints keep their order; a peer connection before the join is the optional early one', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const connect = async (steps: string[]) => { + const scope = new TelemetryScope(pipeline); + scope.connectStarted(CLOUD, granted()); + steps.forEach((step) => scope.connectStep(step)); + scope.connectEnded('ok'); + await pipeline.flush(); + const span = seen.pop() as SpanRecord; + return span.events.map((e) => e.name); + }; + // offer-with-join: the peer connection exists before the join response + expect(await connect(['ws_open', 'signal', 'pc_created', 'join_recv', 'pc_connected'])).toEqual( + ['ws_open', 'signal', 'early_pc_created', 'join_recv', 'pc_created', 'pc_connected'], + ); + // the deferred path: created once the join is adopted + expect(await connect(['ws_open', 'signal', 'join_recv', 'pc_created'])).toEqual([ + 'ws_open', + 'signal', + 'join_recv', + 'pc_created', + ]); + }); + + test('a new connection ends a reconnect in progress as cancelled and releases its hold', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + scope.connectStarted(CLOUD, granted()); + scope.connectEnded('ok'); + scope.reconnectAttempt('quick', ReconnectReason.RR_SIGNAL_DISCONNECTED); + expect(scope.reconnecting).toBe(true); + scope.connectStarted(CLOUD, granted()); + expect(scope.reconnecting).toBe(false); + scope.connectEnded('ok'); + scope.emit('custom.after'); + await flushed(pipeline); + const reconnect = seen.find( + (r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.reconnect', + ); + expect(reconnect?.attributes['lk.outcome']).toBe('cancelled'); + expect(pipeline.stats().cached).toBe(0); // its hold went with it + }); + + test('a warning during a publish points at the publish span, which itself nests under the open connect', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + scope.connectStarted(CLOUD, granted()); + const publish = scope.start('lk.publish', { parent: scope.uplink() }); + scope.log('warn', 'negotiation slow', 'livekit-participant'); + publish.end('ok'); + scope.connectEnded('ok'); + await flushed(pipeline); + const line = seen.find( + (r): r is LogRecord => r.kind === 'log' && r.body === 'negotiation slow', + ); + expect(line?.spanId).toBe(publish.spanId); + const connect = seen.find((r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.connect'); + const span = seen.find((r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.publish'); + expect(span?.parentSpanId).toBe(connect?.spanId); + }); + + test('attributes count stored keys only: the 65th is rejected whatever its name, __proto__ is a key like any other', () => { + const scope = connectedScope(pipeline); + for (let i = 0; i < 63; i += 1) scope.setAttribute(`app.k${i}`, 'v'); + const proto = '__proto__'; + scope.setAttribute(proto, 'proto'); + expect(Object.entries(scope.attributes()).find(([key]) => key === proto)?.[1]).toBe('proto'); + scope.setAttribute('constructor', 'over'); // the 65th key + expect(Object.keys(scope.attributes())).not.toContain('constructor'); + expect(pipeline.stats()['dropped.invalid']).toBe(1); + scope.setAttribute('app.k0', 'replaced'); // an existing key is not a new one + expect(scope.attributes()['app.k0']).toBe('replaced'); + }); + + test('a published track without a reading stops the fast polling after 30 s', () => { + const scope = connectedScope(pipeline); + scope.trackPublished('TR_1'); + expect(scope.statsPollIntervalMs()).toBe(1000); + vi.advanceTimersByTime(30_001); + expect(scope.statsPollIntervalMs()).toBe(pipeline.statsWindowMs / 2); + }); + + test('a failing publisher read does not cost the subscriber its reading', async () => { + vi.useRealTimers(); + const scope = connectedScope(pipeline); + const recorded = vi.spyOn(scope, 'recordPeerStats'); + vi.spyOn(scope, 'statsPollIntervalMs').mockReturnValue(5); + const poller = new StatsPoller(scope, pipeline, { + peers: () => [ + { getStats: () => Promise.reject(new Error('closed')) }, + { getStats: () => Promise.resolve(new Map() as unknown as RTCStatsReport) }, + ], + tracks: () => new Map(), + }); + poller.start(); + await vi.waitFor(() => expect(recorded).toHaveBeenCalled()); + poller.stop(); + }); + + test('an encoder going CPU-limited stretches the cadence at once, and relief applies without a tick', () => { + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'video', direction: 'outbound' } as const]]); + const report = (cpu: number) => + new Map([ + [ + 'o1', + { + id: 'o1', + type: 'outbound-rtp', + trackIdentifier: 'mst', + bytesSent: 1, + qualityLimitationDurations: { cpu, bandwidth: 0, other: 0 }, + }, + ], + ]) as unknown as RTCStatsReport; + expect(pipeline.statsWindowMs).toBe(60_000); + scope.recordPeerStats(report(0), tracks); + scope.recordPeerStats(report(1), tracks); // the CPU duration grew + expect(pipeline.statsWindowMs).toBe(120_000); + vi.advanceTimersByTime(60_001); + expect(pipeline.statsWindowMs).toBe(60_000); + }); + + test('a window closes at its boundary on the pipeline clock, with no further reading', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'audio', direction: 'inbound' } as const]]); + const report = new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst', bytesReceived: 100 }], + ]) as unknown as RTCStatsReport; + scope.recordPeerStats(report, tracks); + vi.advanceTimersByTime(60_000); + await pipeline.flush(); + const window = seen.find( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + expect(window?.attributes['lk.rtc.window_ms']).toBeGreaterThanOrEqual(60_000); + expect(window?.attributes['lk.rtc.bytes']).toBe(100); + }); + + test('counters keep layer history, gauges come only from readings inside the window, idle layers retire', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'video', direction: 'outbound' } as const]]); + const layer = (rid: string, bytesSent: number, rtt: number) => [ + { id: `o-${rid}`, type: 'outbound-rtp', trackIdentifier: 'mst', rid, bytesSent }, + { id: `r-${rid}`, type: 'remote-inbound-rtp', localId: `o-${rid}`, roundTripTime: rtt }, + ]; + const asReport = (stats: object[]) => + new Map(stats.map((s) => [(s as { id: string }).id, s])) as unknown as RTCStatsReport; + scope.recordPeerStats(asReport([...layer('h', 100, 0.5), ...layer('q', 50, 0.5)]), tracks); + scope.closeWindows(); + scope.recordPeerStats(asReport(layer('h', 120, 0.01)), tracks); // q stopped: its bytes stay, its RTT does not + scope.closeWindows(); + vi.advanceTimersByTime(180_001); + scope.recordPeerStats(asReport(layer('h', 130, 0.01)), tracks); // q idle for 3 min: retired + scope.closeWindows(); + await pipeline.flush(); + const windows = seen.filter( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + expect(windows.map((w) => w.attributes['lk.rtc.bytes'])).toEqual([150, 170, 130]); + expect(windows[0].attributes['lk.rtc.rtt_ms.max']).toBeCloseTo(500); + expect(windows[1].attributes['lk.rtc.rtt_ms.max']).toBeCloseTo(10); + }); + + test('a connect accepted during a poll drops that poll’s readings', async () => { + vi.useRealTimers(); + let resolveRead: ((report: RTCStatsReport) => void) | undefined; + const scope = new TelemetryScope(pipeline); + scope.connectStarted('wss://proj-a.livekit.cloud', granted({ jti: 'a' })); + scope.connectEnded('ok'); + const recorded = vi.spyOn(scope, 'recordPeerStats'); + vi.spyOn(scope, 'statsPollIntervalMs').mockReturnValue(5); + const poller = new StatsPoller(scope, pipeline, { + peers: () => [ + { + getStats: () => + new Promise((resolve) => { + resolveRead = resolve; + }), + }, + ], + tracks: () => new Map(), + }); + poller.start(); + await vi.waitFor(() => expect(resolveRead).toBeDefined()); + const answer = resolveRead!; + scope.connectStarted('wss://proj-b.livekit.cloud', granted({ jti: 'b' })); // superseding connect; the poller never stopped + answer(new Map() as unknown as RTCStatsReport); + await sleep(20); + expect(recorded).not.toHaveBeenCalled(); + poller.stop(); + }); + + test('a span or window opened before the Room had a project belongs to its first one, however late it ends', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + const early = scope.start('lk.publish'); // a pre-connect publish + scope.connectStarted('wss://proj-a.livekit.cloud', granted({ jti: 'a' })); + scope.connectEnded('ok'); + scope.setRoom({ sid: 'RA' }); + const tracks = new Map([['mst', { sid: 'TR', kind: 'audio', direction: 'inbound' } as const]]); + const report = new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst', bytesReceived: 100 }], + ]) as unknown as RTCStatsReport; + scope.recordPeerStats(report, tracks); // a window under A + scope.connectStarted('wss://proj-b.livekit.cloud', granted({ jti: 'b' })); // the Room is reused + scope.connectEnded('ok'); + early.end('ok'); // finishes after the reuse: still A's + await flushed(pipeline); + const publish = seen.find((r): r is SpanRecord => r.kind === 'span' && r.name === 'lk.publish'); + expect(publish?.host).toBe('proj-a.livekit.cloud'); + const window = seen.find( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + expect(window?.host).toBe('proj-a.livekit.cloud'); // shipped when the new connect was accepted + expect(window?.attributes['lk.room.sid']).toBe('RA'); + }); + + test('without WeakRef telemetry fails closed; without FinalizationRegistry the opt-out still reaches every live Room', () => { + vi.stubGlobal('WeakRef', undefined); + const plain = new Pipeline(); + expect(plain.enabled).toBe(false); + expect(new TelemetryScope(plain).start('lk.publish').ended).toBe(true); // nothing registered, nothing captured + vi.unstubAllGlobals(); + vi.stubGlobal('FinalizationRegistry', undefined); + const many = new Pipeline(); + const spans = Array.from({ length: 300 }, () => new TelemetryScope(many).start('lk.publish')); + many.disable(); + expect(spans.every((s) => s.ended)).toBe(true); + }); + + test('failed-delete markers follow the store: retired on eviction, bounded, gone at opt-out; an uploaded batch is never a loss', async () => { + const calls = mockFetch(Array.from({ length: 5 }, () => ({ status: 200 }))); + const store = new MemoryStorage(1 << 20, 1); // one slot + store.remove = () => { + throw new Error('locked'); + }; + pipeline.storage = store; + const scope = connectedScope(pipeline); + scope.inCall = false; + const markers = () => (pipeline as unknown as { deleting: Set }).deleting; + for (let i = 0; i < 3; i += 1) { + scope.emit(`custom.${i}`); + await pipeline.flush(); + } + expect(calls).toHaveLength(3); // each batch once + expect(markers().size).toBeLessThanOrEqual(1); // only the batch still in the store + expect(pipeline.stats()['dropped.cache_full']).toBeUndefined(); // uploaded batches leaving the store are no loss + pipeline.disable(); + expect(markers().size).toBe(0); + }); + + test('idle layer histories retire from the window timer, with no further reading', () => { + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'video', direction: 'outbound' } as const]]); + const report = new Map([ + ['o1', { id: 'o1', type: 'outbound-rtp', trackIdentifier: 'mst', rid: 'h', bytesSent: 1 }], + ]) as unknown as RTCStatsReport; + scope.recordPeerStats(report, tracks); + scope.closeWindows(); + const layers = (scope as unknown as { layers: Map }).layers; + expect(layers.size).toBe(1); + vi.advanceTimersByTime(180_001); + expect(layers.size).toBe(0); + }); + + test('cadence relief moves the window boundaries at once', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + pipeline.deviceState({ thermal: 'critical' }); // ×4: windows would close at 240 s + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'audio', direction: 'inbound' } as const]]); + const report = new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst', bytesReceived: 100 }], + ]) as unknown as RTCStatsReport; + scope.recordPeerStats(report, tracks); + vi.advanceTimersByTime(10_000); + pipeline.deviceState({ thermal: 'nominal' }); // relief: the boundary is 60 s again + vi.advanceTimersByTime(50_001); + await pipeline.flush(); + const window = seen.find( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + expect(window).toBeDefined(); + }); + + test('a failing record inside the window timer never escapes', () => { + const scope = connectedScope(pipeline); + const tracks = new Map([['mst', { sid: 'TR', kind: 'audio', direction: 'inbound' } as const]]); + const report = new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst', bytesReceived: 100 }], + ]) as unknown as RTCStatsReport; + scope.recordPeerStats(report, tracks); + vi.spyOn(pipeline, 'record').mockImplementation(() => { + throw new Error('pipeline bug'); + }); + expect(() => vi.advanceTimersByTime(60_000)).not.toThrow(); + }); + + test('any logger obtained through getLogger is captured at warn/error whatever its level, debug never', () => { + const logger = getLogger('some-package'); + logger.setLevel('silent'); + const captured: unknown[][] = []; + setLogCapture((level, msg, context, name) => captured.push([level, msg, context, name])); + logger.warn('pkg warning', { a: 1 }, 'third'); + logger.error('pkg error'); + logger.debug('telemetry: dropped a failing call'); + setLogCapture(undefined); + expect(captured).toEqual([ + [LogLevel.warn, 'pkg warning', { a: 1 }, 'some-package'], + [LogLevel.error, 'pkg error', undefined, 'some-package'], + ]); + }); + + test('a Room’s queued pre-server records are resolved by its first server: self-hosted drops and counts them, nothing unassigned survives', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const scope = new TelemetryScope(pipeline); + scope.emitCustom('early'); + scope.log('warn', 'early warning', 'livekit-room'); + scope.start('lk.publish').end('ok'); + expect(pipeline.stats().queued).toBe(3); // unassigned, waiting for the Room's first server + const policy = pipeline.stats()['policy.no_ingest'] ?? 0; + scope.connectStarted('ws://localhost:7880', 'no-token'); // the first server has no ingest + expect(pipeline.stats().queued).toBe(0); + expect(pipeline.stats()['policy.no_ingest']).toBe(policy + 3); + scope.connectEnded('ok'); + scope.connectStarted('wss://proj-b.livekit.cloud', granted()); // a Cloud project later gets nothing of them + scope.connectEnded('ok'); + await flushed(pipeline); + const names = seen.map((r) => (r.kind === 'span' ? r.name : (r.eventName ?? r.body))); + expect(names).not.toContain('custom.early'); + expect(names).not.toContain('early warning'); + expect(names).not.toContain('lk.publish'); + expect(names).toContain('lk.connect'); // B's own connect + }); + + test('an unavailable listing reconciles nothing: an accepted batch keeps its marker and is never re-sent', async () => { + const calls = mockFetch([{ status: 200 }, { status: 200 }]); + const store = new MemoryStorage(1 << 20, 1); + store.remove = () => { + throw new Error('locked'); + }; + let unavailable = false; + const list = store.pending.bind(store); + store.pending = () => { + if (unavailable) throw new Error('io'); + return list(); + }; + pipeline.storage = store; + const scope = connectedScope(pipeline); + scope.emit('custom.once'); + await pipeline.flush(); // taken by the collector, deletion refused + expect(calls).toHaveLength(1); + unavailable = true; + await pipeline.flush(); // nothing reconciled, nothing sent + expect(pipeline.stats()['cache.list_errors']).toBe(1); + unavailable = false; + await pipeline.flush(); + expect(calls).toHaveLength(1); // the marker survived the outage + }); + + test('at the marker cap nothing new is sent: no live marker is ever evicted', async () => { + const calls = mockFetch(Array.from({ length: 4 }, () => ({ status: 200 }))); + const store = new MemoryStorage(1 << 20, 10); + const remove = store.remove.bind(store); + store.remove = () => { + throw new Error('locked'); + }; + pipeline.storage = store; + (pipeline as unknown as { markerCap: number }).markerCap = 2; + const scope = connectedScope(pipeline); + scope.inCall = false; + const markers = (pipeline as unknown as { deleting: Set }).deleting; + for (let i = 0; i < 3; i += 1) { + scope.emit(`custom.${i}`); + await pipeline.flush(); + } + expect(calls).toHaveLength(2); // the third upload waits + expect(markers.size).toBe(2); + store.remove = remove; // deletions work again: markers retire, the held batch goes + await pipeline.flush(); + expect(calls).toHaveLength(3); + expect(markers.size).toBe(0); + }); + + test('a Room leaving applies cadence relief to the Rooms that stay', async () => { + const seen: TelemetryRecord[] = []; + pipeline.onBatch = (batch) => seen.push(...batch); + mockFetch([]); + const a = connectedScope(pipeline); + const b = connectedScope(pipeline); + const inbound = new Map([ + ['mst-b', { sid: 'TR_B', kind: 'audio', direction: 'inbound' } as const], + ]); + b.recordPeerStats( + new Map([ + ['in1', { id: 'in1', type: 'inbound-rtp', trackIdentifier: 'mst-b', bytesReceived: 100 }], + ]) as unknown as RTCStatsReport, + inbound, + ); + const outbound = new Map([ + ['mst-a', { sid: 'TR_A', kind: 'video', direction: 'outbound' } as const], + ]); + const cpu = (ms: number) => + new Map([ + [ + 'o1', + { + id: 'o1', + type: 'outbound-rtp', + trackIdentifier: 'mst-a', + bytesSent: 1, + qualityLimitationDurations: { cpu: ms, bandwidth: 0, other: 0 }, + }, + ], + ]) as unknown as RTCStatsReport; + a.recordPeerStats(cpu(0), outbound); + a.recordPeerStats(cpu(1), outbound); // A is CPU-limited: every window now closes at 120 s + expect(pipeline.statsWindowMs).toBe(120_000); + vi.advanceTimersByTime(10_000); + a.disconnected(DisconnectReason.CLIENT_INITIATED); // A leaves: relief applies to B now, no tick needed + expect(pipeline.statsWindowMs).toBe(60_000); + vi.advanceTimersByTime(50_001); + await pipeline.flush(); + const windows = seen.filter( + (r): r is LogRecord => r.kind === 'log' && r.eventName === 'lk.rtc.stats.sample', + ); + expect(windows.some((w) => w.attributes['lk.track.sid'] === 'TR_B')).toBe(true); + }); + + test('an opt-out purges the configured host’s cache, whichever is set first', async () => { + const stale = new MemoryStorage(1 << 20, 10); + stale.put('000000000000001_000001_3_l_proj-abc.livekit.cloud', new Uint8Array([1, 2, 3])); + configureTelemetryHost({ storage: stale }); + disableTelemetry(); + expect(stale.pending()).toEqual([]); + // the other order: opting out first, the host configured afterwards + const later = new MemoryStorage(1 << 20, 10); + later.put('000000000000002_000001_3_l_proj-abc.livekit.cloud', new Uint8Array([1, 2, 3])); + configureTelemetryHost({ storage: later }); + expect(later.pending()).toEqual([]); + const calls = mockFetch([]); + const room = telemetry.scope(); // a Room created after the opt-out + room.setServer(CLOUD, granted()); + room.emit('custom.after'); + await telemetry.pipeline.flush(true); + expect(telemetry.pipeline.enabled).toBe(false); + expect(calls).toHaveLength(0); + }); + + test('an answer that lands after the opt-out never refills the cache', async () => { + vi.useRealTimers(); + let release!: () => void; + const held = new Promise((resolve) => { + release = resolve; + }); + let requested = false; + vi.stubGlobal( + 'fetch', + vi.fn(async () => { + requested = true; + await held; + return new Response('', { status: 413 }); // a split would write two halves + }), + ); + const scope = connectedScope(pipeline); + scope.emit('custom.a'); + scope.emit('custom.b'); + const flush = pipeline.flush(); + await vi.waitFor(() => expect(requested).toBe(true)); + pipeline.disable(); + release(); + await flush; + expect(pipeline.stats()).toMatchObject({ cached: 0, queued: 0 }); + }); +}); diff --git a/src/telemetry/telemetrySetup.ts b/src/telemetry/telemetrySetup.ts new file mode 100644 index 0000000000..84e6a1382a --- /dev/null +++ b/src/telemetry/telemetrySetup.ts @@ -0,0 +1,61 @@ +import type { TestProject } from 'vitest/node'; +import { createToken } from '../test/signalToken'; + +/** + * vitest globalSetup for the telemetry e2e story (`telemetry.browser.test.ts`). It runs in Node, + * where it can mint tokens and probe the two services the story needs — a `livekit-server --dev` + * and an OTLP/HTTP collector — and provides the browser what it found. Without either, the story + * skips with the reason printed. + * + * LK_URL livekit-server (default ws://127.0.0.1:7880, keys devkey/secret) + * LK_TELEMETRY_ENDPOINT OTLP/HTTP collector base URL (default http://127.0.0.1:4318) + */ +export default async function setup({ provide }: TestProject) { + const url = process.env.LK_URL ?? 'ws://127.0.0.1:7880'; + const endpoint = (process.env.LK_TELEMETRY_ENDPOINT ?? 'http://127.0.0.1:4318').replace( + /\/$/, + '', + ); + const room = `telemetry-${Date.now()}`; + // On CI the services are declared, so a missing one is a failure, not a skip; give them a minute to come up. + const deadline = Date.now() + (process.env.CI ? 60_000 : 0); + const reachable = async (probe: string, init?: RequestInit): Promise => { + for (;;) { + try { + await fetch(probe, { ...init, signal: AbortSignal.timeout(2000) }); + return true; + } catch { + if (Date.now() >= deadline) return false; + await new Promise((resolve) => setTimeout(resolve, 1000)); + } + } + }; + let unavailable = ''; + if (!(await reachable(url.replace(/^ws/, 'http')))) { + unavailable = `no livekit-server at ${url} (LK_URL)`; + } else if (!(await reachable(`${endpoint}/v1/logs`, { method: 'POST', body: '' }))) { + unavailable = `no OTLP collector at ${endpoint} (LK_TELEMETRY_ENDPOINT)`; + } + if (unavailable && process.env.CI) + throw new Error(`telemetry story cannot run on CI: ${unavailable}`); + if (unavailable) console.warn(`\n[e2e] telemetry story SKIPPED: ${unavailable}\n`); + provide('telemetry', { + url, + endpoint, + unavailable, + publisherToken: await createToken({ room, identity: 'publisher', ttlSeconds: 3600 }), + subscriberToken: await createToken({ room, identity: 'subscriber', ttlSeconds: 3600 }), + }); +} + +declare module 'vitest' { + interface ProvidedContext { + telemetry: { + url: string; + endpoint: string; + unavailable: string; + publisherToken: string; + subscriberToken: string; + }; + } +} diff --git a/vite.config.mjs b/vite.config.mjs index af40737514..774b4ce458 100644 --- a/vite.config.mjs +++ b/vite.config.mjs @@ -44,6 +44,6 @@ export default defineConfig({ environment: 'happy-dom', // e2e tests need a real server + node WebSocket; run them via the // dedicated `pnpm test:e2e` config (vitest.e2e.config.mts), not the unit run. - exclude: [...configDefaults.exclude, '**/*.e2e.test.ts'], + exclude: [...configDefaults.exclude, '**/*.e2e.test.ts', '**/*.browser.test.ts'], }, }); diff --git a/vitest.e2e.config.mts b/vitest.e2e.config.mts index ee34511aa8..6aec13aa52 100644 --- a/vitest.e2e.config.mts +++ b/vitest.e2e.config.mts @@ -1,22 +1,35 @@ import { playwright } from '@vitest/browser-playwright'; import { defineConfig } from 'vitest/config'; -// End-to-end signal-connection tests. Unlike the unit suite (happy-dom, mocked -// transport), these run in a REAL browser (Chromium via Playwright) so they -// exercise the actual browser WebSocket + fetch the SDK ships against, driving -// a live mock server (../livekit-server/cmd/test-server) spawned by globalSetup. +// End-to-end tests. Unlike the unit suite (happy-dom, mocked transport), these run in a REAL +// browser (Chromium via Playwright) so they exercise the actual browser WebSocket + fetch the SDK +// ships against: +// - the signal-connection suite drives a live mock server (../livekit-server/cmd/test-server) +// spawned by its globalSetup; +// - the telemetry story runs a whole call on a `livekit-server --dev` and reports it to an OTLP +// collector, both probed by its globalSetup (skipped when unreachable). +const collector = (process.env.LK_TELEMETRY_ENDPOINT ?? 'http://127.0.0.1:4318').replace(/\/$/, ''); + export default defineConfig({ + server: { + // The telemetry story reaches its collector through the test page's own origin, so the + // collector needs no CORS configuration. + proxy: { '/__otlp': { target: collector, rewrite: (path) => path.replace(/^\/__otlp/, '') } }, + }, test: { - include: ['src/**/*.e2e.test.ts'], - // globalSetup runs in Node (spawns the Go mock); tests run in the browser. - globalSetup: ['./src/test/signalServerSetup.ts'], + include: ['src/**/*.e2e.test.ts', 'src/telemetry/*.browser.test.ts'], + // globalSetup runs in Node (spawns the Go mock, mints tokens); tests run in the browser. + globalSetup: ['./src/test/signalServerSetup.ts', './src/telemetry/telemetrySetup.ts'], testTimeout: 20_000, hookTimeout: 120_000, // One browser context; scenarios isolate via unique-per-mode room names. fileParallelism: false, browser: { enabled: true, - provider: playwright(), + provider: playwright({ + // The telemetry story's mock media is an oscillator: let the AudioContext run without a gesture. + launchOptions: { args: ['--autoplay-policy=no-user-gesture-required'] }, + }), headless: true, instances: [{ browser: 'chromium' }], screenshotFailures: false, diff --git a/vitest.telemetry.config.mts b/vitest.telemetry.config.mts new file mode 100644 index 0000000000..4542335bfa --- /dev/null +++ b/vitest.telemetry.config.mts @@ -0,0 +1,13 @@ +import { defineConfig } from 'vitest/config'; +import e2e from './vitest.e2e.config.mts'; + +// The telemetry story alone (same browser, same setup as `pnpm test:e2e`): +// pnpm vitest run --config vitest.telemetry.config.mts +export default defineConfig({ + ...e2e, + test: { + ...e2e.test, + include: ['src/telemetry/*.browser.test.ts'], + globalSetup: ['./src/telemetry/telemetrySetup.ts'], + }, +}); From f696c752f43fc2d2a9047478a0082fdadb5dbb0b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?B=C5=82az=CC=87ej=20Pankowski?= <86720177+pblazej@users.noreply.github.com> Date: Fri, 2 Oct 2026 13:59:11 +0200 Subject: [PATCH 7/7] chore(telemetry): changeset, size budget and module map The UMD size limit moves from 130 to 140 kB for the pipeline and encoder; TELEMETRY.md is a short map of the module for maintainers. --- .changeset/client-telemetry-pipeline.md | 5 +++++ .size-limit.cjs | 5 ++++- TELEMETRY.md | 20 ++++++++++++++++++++ 3 files changed, 29 insertions(+), 1 deletion(-) create mode 100644 .changeset/client-telemetry-pipeline.md create mode 100644 TELEMETRY.md diff --git a/.changeset/client-telemetry-pipeline.md b/.changeset/client-telemetry-pipeline.md new file mode 100644 index 0000000000..a0f8106bf1 --- /dev/null +++ b/.changeset/client-telemetry-pipeline.md @@ -0,0 +1,5 @@ +--- +'livekit-client': minor +--- + +Add client telemetry: every Room on LiveKit Cloud reports its connect, reconnect, publish and subscribe spans, RTC statistics windows, SDK warnings and device state to its own project when the token carries the observability grant; `disableTelemetry()` opts the process out, `Room.emitTelemetryEvent()` and `Room.setTelemetryAttribute()` add the app's own events and correlation ids. diff --git a/.size-limit.cjs b/.size-limit.cjs index 81a6ad3fb3..437e2abff3 100644 --- a/.size-limit.cjs +++ b/.size-limit.cjs @@ -7,6 +7,9 @@ module.exports = [ { path: 'dist/livekit-client.umd.js', import: '{ Room }', - limit: '130 kB', + // Telemetry cannot be shaken out of the UMD bundle: 130 kB no longer fits, and after the + // review rounds the bundle sits at the 135 kB raised first. Raising it is one of two answers — + // the other is a separate UMD entry point, as the e2ee and frame-metadata workers already have. + limit: '140 kB', }, ]; diff --git a/TELEMETRY.md b/TELEMETRY.md new file mode 100644 index 0000000000..f84232535c --- /dev/null +++ b/TELEMETRY.md @@ -0,0 +1,20 @@ +# Client telemetry (maintainers) + +The contract — events, attributes, cadences, destination and upload policy — is +[`livekit-telemetry/SPEC.md`](https://github.com/livekit/rust-sdks/blob/main/livekit-telemetry/SPEC.md) +in rust-sdks. The Swift, Kotlin and Dart SDKs get it from the Rust core; a browser cannot link +that core, so `src/telemetry/` is the same pipeline in TypeScript, and `@livekit/react-native` +reuses it (it only wires `configureTelemetryHost()`: a file cache, device state, resource names). + +| File | Role | +|---|---| +| `index.ts` | installs the pipeline with the first Room; `disableTelemetry()`; the host hook; SDK warn/error capture | +| `scope.ts` | one per Room: trace id, Room attributes, `lk.connect` / `lk.reconnect` / `lk.publish` / `lk.subscribe`, RTC windows, the two app calls | +| `pipeline.ts` | queue → write-ahead cache → one request in flight; projects, tokens, holds, budget, the answer table, the self-report, opt-out | +| `transport.ts` | Cloud URL rules, token claims, answer classification, Retry-After, backoff, the request | +| `otlp.ts` | record shapes and a protobuf writer for the two OTLP export requests | +| `webrtc.ts`, `poller.ts` | one `getStats()` per peer connection → SPEC readings → windows | +| `storage.ts`, `device.ts` | the cache interface and memory store; device state → events, cadence, holds | + +Tests: `telemetry.test.ts` (unit, mock fetch) and `telemetry.browser.test.ts` (the whole story in +Chromium against `livekit-server --dev` and a local collector; see the PR for the commands).