diff --git a/src/perf/assert-spans.test.ts b/src/perf/assert-spans.test.ts new file mode 100644 index 000000000..1ca284142 --- /dev/null +++ b/src/perf/assert-spans.test.ts @@ -0,0 +1,264 @@ +/** + * Latency eval harness: assert helpers over PerfTrace snapshots and rollups. + * + * This layer owns: + * - assert API behavior (pass paths + negative branches) + * - golden multi-tool fixture equality (locked TurnSummary) + * - one end-to-end smoke: reactor observer → snapshot → rollup → asserts + * + * Rollup arithmetic (phase totals, sessionTotals, percentiles) lives in + * rollup.test.ts — do not re-test pure rollup math here. + * + * Covers CL-5174 outcomes: + * - phase presence + nesting helpers + * - regression: turn has inference + tools when tools ran + * - golden multi-tool fixture rollup + * - full observer pipeline → snapshot → rollup → assertions + */ + +import { afterEach, describe, expect, test } from "bun:test"; +import type { ReactorEmittedEvent } from "@intx/inference"; +import { + assertLessThan, + assertNesting, + assertPhasePresent, + assertPhaseSummary, + assertTurnHasInferenceAndTools, +} from "./assert-spans.js"; +import { + MULTI_TOOL_TURN_GOLDEN, + multiToolTurnFixture, +} from "./fixtures/multi-tool-turn.js"; +import { ALLOWED_TAG_KEYS, clear, snapshot, type PerfSpan } from "./index.js"; +import { createPerfReactorObserver } from "./reactor-spans.js"; +import { rollupByPhase, rollupByTurn, type TurnSummary } from "./rollup.js"; + +afterEach(() => { + clear(); +}); + +const ALLOWED_TAG_KEY_SET: ReadonlySet = new Set(ALLOWED_TAG_KEYS); + +function event(type: string, data: unknown = {}): ReactorEmittedEvent { + return { type, seq: 1, data } as ReactorEmittedEvent; +} + +const emptyUsage = { input: 10, output: 5, cacheRead: 0, cacheWrite: 0, thinking: 0 }; +const source = { provider: "test-provider", model: "test-model" }; + +function inferenceDone(content: unknown[] = [{ type: "text", text: "hi" }]): ReactorEmittedEvent { + return event("inference.done", { + turn: { role: "assistant", content, model: "test-model", timestamp: 0 }, + usage: emptyUsage, + source, + }); +} + +function completed(spans: PerfSpan[]): PerfSpan[] { + return spans.filter((s) => s.endNs !== undefined); +} + +function turnSummary(partial: Partial & Pick): TurnSummary { + return { + turnNs: 1000, + open: false, + inferenceNs: 500, + toolNs: 200, + ttftNs: 100, + streamNs: 400, + toolCount: 1, + ...partial, + }; +} + +describe("assertPhasePresent / assertNesting", () => { + test("assertPhasePresent finds phases on the golden fixture", () => { + const spans = multiToolTurnFixture(); + assertPhasePresent(spans, "turn"); + assertPhasePresent(spans, "inference"); + assertPhasePresent(spans, "inference.ttft"); + assertPhasePresent(spans, "inference.stream"); + assertPhasePresent(spans, "tool"); + assertPhasePresent(spans, "permission.wait"); + }); + + test("assertPhasePresent throws when phase is missing", () => { + expect(() => assertPhasePresent(multiToolTurnFixture(), "subagent")).toThrow( + /expected phase "subagent"/, + ); + }); + + test("assertNesting verifies parent-child links (child, parent arg order)", () => { + const spans = multiToolTurnFixture(); + // child first, then expected parent + assertNesting(spans, "inference", "turn"); + assertNesting(spans, "inference.ttft", "inference"); + assertNesting(spans, "inference.stream", "inference"); + assertNesting(spans, "tool", "turn"); + assertNesting(spans, "permission.wait", "turn"); + }); + + test("assertNesting throws when link is absent", () => { + expect(() => assertNesting(multiToolTurnFixture(), "tool", "inference")).toThrow( + /expected nesting inference → tool/, + ); + }); +}); + +describe("assertPhaseSummary", () => { + test("passes on golden phase rollup with minCount and minTotalNs", () => { + const phases = rollupByPhase(multiToolTurnFixture()); + assertPhaseSummary(phases, "turn", { minCount: 1, minTotalNs: 5000 }); + assertPhaseSummary(phases, "inference", { minCount: 1, minTotalNs: 2000 }); + assertPhaseSummary(phases, "tool", { minCount: 2, minTotalNs: 1200 }); + assertPhaseSummary(phases, "permission.wait", { minCount: 1, minTotalNs: 400 }); + }); + + test("throws when phase summary is missing", () => { + const phases = rollupByPhase(multiToolTurnFixture()); + expect(() => assertPhaseSummary(phases, "subagent")).toThrow( + /expected phase summary "subagent"/, + ); + }); + + test("throws when count is below minCount", () => { + const phases = rollupByPhase(multiToolTurnFixture()); + expect(() => assertPhaseSummary(phases, "tool", { minCount: 3 })).toThrow( + /phase "tool": expected count >= 3/, + ); + }); + + test("throws when totalNs is below minTotalNs", () => { + const phases = rollupByPhase(multiToolTurnFixture()); + expect(() => + assertPhaseSummary(phases, "inference", { minTotalNs: 999_999 }), + ).toThrow(/phase "inference": expected totalNs >= 999999/); + }); +}); + +describe("assertLessThan", () => { + test("passes when left < right", () => { + assertLessThan(400, 1600, "ttft vs stream"); + }); + + test("throws when left >= right", () => { + expect(() => assertLessThan(1600, 400, "ttft vs stream")).toThrow( + /ttft vs stream: expected 1600 < 400/, + ); + expect(() => assertLessThan(5, 5, "eq")).toThrow(/eq: expected 5 < 5/); + }); +}); + +describe("assertTurnHasInferenceAndTools", () => { + test("passes on multi-tool golden rollup", () => { + const turns = rollupByTurn(multiToolTurnFixture()); + assertTurnHasInferenceAndTools(turns[0]!); + assertTurnHasInferenceAndTools(turns[0]!, { minToolCount: 2 }); + }); + + test("throws when inferenceNs is not positive", () => { + expect(() => + assertTurnHasInferenceAndTools(turnSummary({ turnId: "t-no-inf", inferenceNs: 0 })), + ).toThrow(/turn t-no-inf: expected inferenceNs > 0/); + }); + + test("throws when toolCount is below minimum", () => { + const noTools = turnSummary({ turnId: "t-no-tools", toolCount: 0, toolNs: 0 }); + expect(() => assertTurnHasInferenceAndTools(noTools)).toThrow( + /turn t-no-tools: expected toolCount >= 1/, + ); + + const oneTool = turnSummary({ turnId: "t-one", toolCount: 1, toolNs: 100 }); + expect(() => assertTurnHasInferenceAndTools(oneTool, { minToolCount: 2 })).toThrow( + /turn t-one: expected toolCount >= 2/, + ); + }); + + test("throws when toolNs is not positive despite toolCount", () => { + expect(() => + assertTurnHasInferenceAndTools( + turnSummary({ turnId: "t-zero-tool-ns", toolCount: 1, toolNs: 0 }), + ), + ).toThrow(/turn t-zero-tool-ns: expected toolNs > 0/); + }); + + test("fails when tools are filtered out of the golden fixture", () => { + const spans: PerfSpan[] = multiToolTurnFixture().filter((s) => s.name !== "tool"); + const turns = rollupByTurn(spans); + expect(() => assertTurnHasInferenceAndTools(turns[0]!)).toThrow(/toolCount/); + }); +}); + +describe("golden multi-tool turn fixture", () => { + test("rollupByTurn matches locked golden values", () => { + const turns = rollupByTurn(multiToolTurnFixture()); + expect(turns).toHaveLength(1); + expect(turns[0]).toEqual({ ...MULTI_TOOL_TURN_GOLDEN }); + }); + + test("fixture tags are privacy-safe (allowlisted keys only)", () => { + for (const span of multiToolTurnFixture()) { + if (span.tags === undefined) continue; + for (const key of Object.keys(span.tags)) { + expect(ALLOWED_TAG_KEY_SET.has(key)).toBe(true); + } + } + }); + + test("TTFT is strictly less than stream on the golden fixture", () => { + const turn = rollupByTurn(multiToolTurnFixture())[0]!; + assertLessThan(turn.ttftNs, turn.streamNs, "ttft vs stream"); + }); +}); + +describe("observer pipeline → snapshot → rollup → assertions", () => { + test("multi-tool reactor events produce assertable turn rollup", () => { + const obs = createPerfReactorObserver(); + + obs.observe(event("inference.start", { model: "test-model" })); + obs.observe(event("inference.text.delta", { token: "x", partial: { text: "x" } })); + obs.observe( + inferenceDone([ + { type: "tool_call", id: "call-a", name: "read_file", arguments: {} }, + { type: "tool_call", id: "call-b", name: "edit_file", arguments: {} }, + ]), + ); + obs.observe(event("tool.start", { call: { id: "call-a", name: "read_file", arguments: {} } })); + obs.observe(event("tool.done", { result: { callId: "call-a", content: "ok" } })); + obs.observe(event("tool.start", { call: { id: "call-b", name: "edit_file", arguments: {} } })); + obs.observe(event("tool.done", { result: { callId: "call-b", content: "ok" } })); + + const spans = completed(snapshot()); + + assertPhasePresent(spans, "turn"); + assertPhasePresent(spans, "inference"); + assertPhasePresent(spans, "inference.ttft"); + assertPhasePresent(spans, "inference.stream"); + assertPhasePresent(spans, "tool"); + + assertNesting(spans, "inference", "turn"); + assertNesting(spans, "inference.ttft", "inference"); + assertNesting(spans, "inference.stream", "inference"); + assertNesting(spans, "tool", "turn"); + + const turns = rollupByTurn(spans); + expect(turns).toHaveLength(1); + assertTurnHasInferenceAndTools(turns[0]!, { minToolCount: 2 }); + expect(turns[0]!.toolCount).toBe(2); + + // Live clock: duration magnitudes are non-deterministic under sync hrtime + // (ttftNs can exceed streamNs). Assert wall ordering instead of a no-op + // `>= 0` check: TTFT must end at or before stream starts when both exist. + const ttft = spans.find((s) => s.name === "inference.ttft"); + const stream = spans.find((s) => s.name === "inference.stream"); + expect(ttft?.endNs).toBeDefined(); + expect(stream?.startNs).toBeDefined(); + if (ttft!.endNs !== undefined && stream !== undefined) { + expect(ttft!.endNs <= stream.startNs).toBe(true); + } + + const phases = rollupByPhase(spans); + assertPhaseSummary(phases, "tool", { minCount: 2 }); + assertPhaseSummary(phases, "inference", { minCount: 1 }); + }); +}); diff --git a/src/perf/assert-spans.ts b/src/perf/assert-spans.ts new file mode 100644 index 000000000..91949c968 --- /dev/null +++ b/src/perf/assert-spans.ts @@ -0,0 +1,127 @@ +/** + * Eval / test harness assertions over PerfTrace snapshots and rollups. + * + * Pure helpers: throw Error with a clear message on failure (no bun:test import). + * Use from unit tests, capability evals, or ad-hoc scripts after snapshot()/rollup. + */ + +import type { PerfSpan, SpanName } from "./index.js"; +import type { PhaseSummary, TurnSummary } from "./rollup.js"; +import { spanDurationNs } from "./rollup.js"; + +/** Verify at least one span with the given phase name exists. */ +export function assertPhasePresent( + spans: readonly PerfSpan[], + phaseName: SpanName | string, +): void { + const found = spans.some((s) => s.name === phaseName); + if (!found) { + const names = [...new Set(spans.map((s) => s.name))].sort().join(", "); + throw new Error( + `expected phase "${phaseName}" in snapshot; present phases: [${names || "none"}]`, + ); + } +} + +/** + * Verify at least one span named `childName` is nested under a span named + * `parentName` (via parentId → id). + * + * Arg order: (spans, child, parent) — the nested phase first, then its expected + * parent. Example: `assertNesting(spans, "inference", "turn")` means an + * inference span has parentId pointing at a turn span. + */ +export function assertNesting( + spans: readonly PerfSpan[], + childName: SpanName | string, + parentName: SpanName | string, +): void { + const byId = new Map(spans.map((s) => [s.id, s])); + const ok = spans.some((child) => { + if (child.name !== childName || child.parentId === undefined) return false; + const parent = byId.get(child.parentId); + return parent !== undefined && parent.name === parentName; + }); + if (!ok) { + throw new Error( + `expected nesting ${parentName} → ${childName}; no matching parentId link found`, + ); + } +} + +export type TurnInferenceToolsOpts = { + /** Minimum tool invocations required (default 1). */ + minToolCount?: number; +}; + +/** + * Regression: a turn that ran tools must report positive inference and tool cost. + * Accepts a single TurnSummary (from rollupByTurn). + */ +export function assertTurnHasInferenceAndTools( + turn: TurnSummary, + opts?: TurnInferenceToolsOpts, +): void { + const minToolCount = opts?.minToolCount ?? 1; + if (turn.inferenceNs <= 0) { + throw new Error( + `turn ${turn.turnId}: expected inferenceNs > 0, got ${turn.inferenceNs}`, + ); + } + if (turn.toolCount < minToolCount) { + throw new Error( + `turn ${turn.turnId}: expected toolCount >= ${minToolCount} when tools ran, got ${turn.toolCount}`, + ); + } + if (turn.toolNs <= 0) { + throw new Error( + `turn ${turn.turnId}: expected toolNs > 0 when tools ran, got ${turn.toolNs}`, + ); + } +} + +/** + * Assert a < b for relative magnitude checks (e.g. TTFT < stream wall). + * Values are plain numbers (typically nanoseconds from rollup). + */ +export function assertLessThan( + left: number, + right: number, + label = "magnitude", +): void { + if (!(left < right)) { + throw new Error(`${label}: expected ${left} < ${right}`); + } +} + +/** + * Assert a phase summary exists in a rollupByPhase result and has count >= minCount. + */ +export function assertPhaseSummary( + phases: readonly PhaseSummary[], + phaseName: SpanName | string, + opts?: { minCount?: number; minTotalNs?: number }, +): PhaseSummary { + const phase = phases.find((p) => p.name === phaseName); + if (phase === undefined) { + const names = phases.map((p) => p.name).join(", "); + throw new Error( + `expected phase summary "${phaseName}"; present: [${names || "none"}]`, + ); + } + const minCount = opts?.minCount ?? 1; + if (phase.count < minCount) { + throw new Error( + `phase "${phaseName}": expected count >= ${minCount}, got ${phase.count}`, + ); + } + if (opts?.minTotalNs !== undefined && phase.totalNs < opts.minTotalNs) { + throw new Error( + `phase "${phaseName}": expected totalNs >= ${opts.minTotalNs}, got ${phase.totalNs}`, + ); + } + return phase; +} + +/** Span duration helper re-export for eval scripts that only import assertions. */ +export { spanDurationNs }; diff --git a/src/perf/fixtures/multi-tool-turn.ts b/src/perf/fixtures/multi-tool-turn.ts new file mode 100644 index 000000000..4fdd3cc7c --- /dev/null +++ b/src/perf/fixtures/multi-tool-turn.ts @@ -0,0 +1,106 @@ +/** + * Golden fixture: one multi-tool turn with nested inference and permission wait. + * + * Privacy-safe: only allowlisted tags (tool_id, model_id, provider_id, tokens). + * Fixed nanosecond times — no live clock. Durations: + * + * turn t1 0 → 5000 + * inference i1 100 → 2100 (2000ns) + * inference.ttft 100 → 500 ( 400ns) + * inference.stream 500 → 2100 (1600ns) + * permission.wait 2100 → 2500 ( 400ns) + * tool k1 2500 → 3200 ( 700ns) tool_id=read_file + * tool k2 3300 → 3800 ( 500ns) tool_id=edit_file + * + * TTFT (400) < stream (1600). Two tools under the turn. + */ + +import type { PerfSpan } from "../index.js"; + +function span(partial: { + id: string; + name: PerfSpan["name"]; + parentId?: string; + startNs: bigint; + endNs?: bigint; + tags?: PerfSpan["tags"]; +}): PerfSpan { + const s: PerfSpan = { + id: partial.id, + name: partial.name, + startNs: partial.startNs, + }; + if (partial.parentId !== undefined) s.parentId = partial.parentId; + if (partial.endNs !== undefined) s.endNs = partial.endNs; + if (partial.tags !== undefined) s.tags = partial.tags; + return s; +} + +/** Synthetic multi-tool turn tree for rollup / assertion regression tests. */ +export function multiToolTurnFixture(): PerfSpan[] { + return [ + span({ id: "t1", name: "turn", startNs: 0n, endNs: 5000n, tags: { turn_id: "turn-1" } }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 100n, + endNs: 2100n, + tags: { + provider_id: "test-provider", + model_id: "test-model", + input_tokens: 120, + output_tokens: 40, + }, + }), + span({ + id: "ttft1", + name: "inference.ttft", + parentId: "i1", + startNs: 100n, + endNs: 500n, + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 500n, + endNs: 2100n, + }), + span({ + id: "pw1", + name: "permission.wait", + parentId: "t1", + startNs: 2100n, + endNs: 2500n, + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 2500n, + endNs: 3200n, + tags: { tool_id: "read_file" }, + }), + span({ + id: "k2", + name: "tool", + parentId: "t1", + startNs: 3300n, + endNs: 3800n, + tags: { tool_id: "edit_file" }, + }), + ]; +} + +/** Expected turn rollup for multiToolTurnFixture (locked golden values). */ +export const MULTI_TOOL_TURN_GOLDEN = { + turnId: "t1", + turnNs: 5000, + open: false, + inferenceNs: 2000, + toolNs: 1200, + ttftNs: 400, + streamNs: 1600, + toolCount: 2, +} as const;