Files
PaperClipAI/tests/runner-e2e/latency-timing.ts
T
DottaandPaperclip 53732c811b fix(evals): classify latency from observation bounds (#16829)
## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work.
> - Product E2E probes measure when acknowledgements and replies become
visible.
> - A poll gives a time interval for an event.
> - The first positive poll can occur after a target that the event
could still meet.
> - This pull request compares the full interval with a strict or
inclusive target.
> - Reports retain the raw observations and the original verdict when
the timing verdict changes.

## Linked Issues or Issue Description

**What happened?**

A historical acknowledgement was absent at 1901 ms and first present at
2427 ms. A report marked the 2000 ms target as failed. The interval
crosses that target, so the available evidence cannot give a pass or
fail verdict.

**Expected behavior**

Return pass when the full interval meets the target. Return fail when
the full interval rules out the target. Return inconclusive for overlap,
invalid evidence, or insufficient evidence. Respect strict and inclusive
targets and open and closed endpoints.

**Steps to reproduce**

Run the deterministic timing tests. Use the acknowledgement interval
`(1901, 2427] ms` with `<= 2000 ms`. Compare the late reply interval
`(52965, 53334] ms` with `<= 30000 ms`. The first is inconclusive. The
second fails.

**Paperclip version or commit**

The source includes master at
`14afc12124017d4ec30d0f4bfd6892f8ce475d21`.

Related PR:
[#13710](https://github.com/paperclipai/paperclip/pull/13710) changed
chat latency and session reuse. This change corrects probe evidence and
report verdicts.

## What Changed

- Add a shared interval classifier with explicit endpoint and target
operators.
- Start observation before dispatch. Use a monotonic clock. Bound
asynchronous reads by request start and completion.
- Measure the first visible response separately from message creation
and final settlement. Share browser reads with an optional
acknowledgement probe.
- Keep raw bounds, clock resolution, message metadata, failed reads, and
original verdicts in retained report evidence.
- Add deterministic coverage for threshold equality, missing data,
edited messages, asynchronous reads, teardown, report correction, and a
finite-domain oracle.
- Bound observer shutdown to one second across pending and final reads.
Retain timeout counts. Ignore late completions and start no more reads
after shutdown.
- Document the timing contract in the existing Product E2E guide.
- Keep current startup reuse evidence after the master merge. Update
four stale test expectations for qualified Copilot admission. Keep the
explicit suite and provider restrictions.

## Verification

- Current head: `c42e87e6d3b4b347e7cb176f56819c1d0abe106d`.
- Passed: `pnpm test:e2e:runner:unit` (3,287 Vitest tests and 128 native
completion tests; two explicit skips).
- Passed: `pnpm test:e2e:runner:typecheck`, `pnpm -r typecheck`, `pnpm
build`, `pnpm check:token-gates`, and `git diff origin/master --check`.
- Passed: [exact-head
CI](https://github.com/paperclipai/paperclip/actions/runs/39607140418),
including both required checks (`ci / verify` and `ci / e2e`), all
general and serialized test jobs, all eight browser shards, build,
canary dry run, and the clean public npm-install smoke.
- Greptile reviewed the complete current diff and returned [5/5 with no
actionable
issues](https://github.com/paperclipai/paperclip/pull/16829#issuecomment-6266704814).
All review threads are resolved.
- The redundant local `pnpm test:run` was stopped after the exact-head
CI test jobs passed. It did not produce a complete local verdict; the
full repository test evidence is the CI run above.
- The [earlier broad
run](https://github.com/paperclipai/paperclip/actions/runs/39249282597)
failed on the old head. Its full test command timed out after 15
minutes. Five E2E support failures came from ambient `NODE_PATH` and a
missing historical Git object. Current master supplies the
closed-environment launcher and retained source fixture. The full
support suite passes with these fixes.
- After the current master merge, four stale Copilot assertions and the
nested unit launcher failed. Copilot is now qualified. Those assertions
now require no qualification override and retain the rejected
suite/provider cases. The full documented unit command passes.
- The first local typecheck after the merge used stale generated package
declarations and failed. The typechecks pass after `pnpm build`.
- These checks use synthetic timing evidence. They make no live provider
calls and claim no new live latency measurement.

## Risks

- The browser diagnostic depends on the existing message and receipt DOM
markers. Controlled tests cover visibility, receipt separation,
concurrent reads, and teardown.
- Corrected timing verdicts can become inconclusive. The report keeps
the original verdict and does not change the overall workflow grade.
- This change adds no database migration or product surface.

## Model Used

- OpenAI GPT-6 Codex. Model family: GPT-6. This session does not expose
a more specific model ID or context window size. The agent used
reasoning, shell tools, code inspection, and deterministic tests. The
earlier implementation session did not retain its exact model ID.

## Checklist

- [x] I have included a thinking path that traces from project context
to this change
- [x] I have specified the model used (with version and capability
details)
- [x] I have checked ROADMAP.md and confirmed this PR does not duplicate
planned core work
- [x] I have searched GitHub for duplicate or related PRs and linked
them above
- [x] I have either (a) linked existing issues with `Fixes: #` / `Closes
#` / `Refs #` OR (b) described the issue in-PR following the relevant
issue template
- [x] I have not referenced internal/instance-local Paperclip issues or
links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip`
URLs)
- [x] My branch name describes the change (e.g. `docs/...`, `fix/...`)
and contains no internal Paperclip ticket id or instance-derived details
- [x] I have run tests locally and they pass
- [x] I have added or updated tests where applicable
- [x] I have updated relevant documentation to reflect my changes
- [x] I have considered and documented any risks above
- [x] All Paperclip CI gates are green
- [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups
- [x] I will address all Greptile and reviewer comments before
requesting merge

---------

Co-authored-by: Paperclip <noreply@paperclip.ing>
2026-10-21 08:31:22 -05:00

131 lines
6.1 KiB
TypeScript

/** Probe timing is an interval, never the timestamp of the poll that found it. */
export type LatencyEvent = "acknowledgement" | "first_visible_response" | "message_creation" | "final_settlement";
export type LatencyVerdict = "pass" | "fail" | "inconclusive";
export interface TimingBound { ms: number; inclusive: boolean }
export interface LatencyTarget { operator: "<" | "<="; ms: number }
export interface LatencyEvidence {
event: LatencyEvent;
interval: { lower: TimingBound | null; upper: TimingBound | null };
lastAbsentMs: number | null;
firstPresentMs: number | null;
/** Conservative uncertainty on each elapsed observation; null means unknown. */
resolutionMs: number | null;
invalid?: boolean;
observationFailures?: number;
/** Reads abandoned when the browser observer's shutdown deadline expires. */
observationTimeouts?: number;
/** Provider wall-clock metadata is retained separately and never measures visibility. */
messageTimestamps?: { createdAt?: string; editedAt?: string };
}
export interface LatencyResult extends LatencyEvidence {
target: LatencyTarget;
verdict: LatencyVerdict;
/** Original retained verdict, if report regeneration corrects the timing grade. */
recordedVerdict?: LatencyVerdict;
reason: "within_target" | "outside_target" | "threshold_overlap" | "missing_observations" | "invalid_evidence" | "unknown_resolution";
}
const nonnegative = (value: unknown): value is number =>
typeof value === "number" && Number.isFinite(value) && value >= 0;
export function classifyLatency(evidence: LatencyEvidence, target: LatencyTarget): LatencyResult {
const { lower, upper } = evidence.interval ?? {};
const result = (verdict: LatencyVerdict, reason: LatencyResult["reason"]): LatencyResult =>
({ ...evidence, target, verdict, reason });
const validBound = (bound: TimingBound | null) => bound === null
|| (bound && nonnegative(bound.ms) && typeof bound.inclusive === "boolean");
if (evidence.invalid || !nonnegative(target.ms) || !["<", "<="].includes(target.operator)
|| !validBound(lower) || !validBound(upper)
|| (evidence.lastAbsentMs !== null && !nonnegative(evidence.lastAbsentMs))
|| (evidence.firstPresentMs !== null && !nonnegative(evidence.firstPresentMs))
|| (evidence.lastAbsentMs !== null && evidence.firstPresentMs !== null && evidence.lastAbsentMs > evidence.firstPresentMs)
|| (lower && upper && (lower.ms > upper.ms || (lower.ms === upper.ms && !(lower.inclusive && upper.inclusive))))
|| (evidence.resolutionMs !== null && !nonnegative(evidence.resolutionMs))) {
return result("inconclusive", "invalid_evidence");
}
if (evidence.resolutionMs === null) return result("inconclusive", "unknown_resolution");
if (!lower && !upper) return result("inconclusive", "missing_observations");
if (upper && (upper.ms < target.ms || (upper.ms === target.ms && (target.operator === "<=" || !upper.inclusive)))) {
return result("pass", "within_target");
}
if (lower && (lower.ms > target.ms || (lower.ms === target.ms && (target.operator === "<" || !lower.inclusive)))) {
return result("fail", "outside_target");
}
return result("inconclusive", "threshold_overlap");
}
export function observationTiming(input: Omit<LatencyEvidence, "interval">): LatencyEvidence {
const uncertainty = input.resolutionMs ?? 0;
return {
...input,
interval: {
lower: input.lastAbsentMs === null ? null : { ms: Math.max(0, input.lastAbsentMs - uncertainty), inclusive: input.lastAbsentMs - uncertainty < 0 },
upper: input.firstPresentMs === null ? null : { ms: input.firstPresentMs + uncertainty, inclusive: true },
},
};
}
/** Arm immediately before dispatch. Inject a monotonic clock for deterministic tests.
* The predicate must describe a persistent event (or a latched event observer).
* A missing/failed read is not an absent observation. */
export function armLatencyProbe(input: {
event: LatencyEvent;
target: LatencyTarget;
resolutionMs: number;
now?: () => number;
}) {
const now = input.now ?? (() => performance.now());
const start = now();
let lastClock = start;
let invalid = !Number.isFinite(start);
let lastAbsentMs: number | null = null;
let firstPresentMs: number | null = null;
let observationFailures = 0;
let messageTimestamps: LatencyEvidence["messageTimestamps"];
const elapsed = () => {
const current = now();
if (!Number.isFinite(current) || current < lastClock) invalid = true;
lastClock = current;
return current - start;
};
type Observation = { present: boolean; messageTimestamps?: LatencyEvidence["messageTimestamps"] };
const beginObservation = () => {
const before = elapsed();
let completed = false;
return (observation: Observation) => {
if (completed) throw new Error("Observation already completed");
completed = true;
const after = elapsed();
if (typeof observation.present !== "boolean" || after < before) invalid = true;
// Concurrent or late reads cannot replace the first positive observation.
if (firstPresentMs !== null) return;
if (observation.present) {
firstPresentMs = after;
messageTimestamps = observation.messageTimestamps;
} else {
lastAbsentMs = Math.max(lastAbsentMs ?? 0, before);
}
};
};
return {
beginObservation,
async sample(load: () => Promise<Observation>) {
if (firstPresentMs !== null) return;
const complete = beginObservation();
try { complete(await load()); }
catch (error) { observationFailures++; throw error; }
},
result(): LatencyResult {
return classifyLatency(observationTiming({ event: input.event, lastAbsentMs, firstPresentMs,
resolutionMs: input.resolutionMs, ...(invalid ? { invalid: true } : {}),
...(observationFailures ? { observationFailures } : {}),
...(messageTimestamps ? { messageTimestamps } : {}) }), input.target);
},
};
}
export function latencyIntervalLabel(evidence: LatencyEvidence): string {
const { lower, upper } = evidence.interval;
return `${lower?.inclusive ? "[" : "("}${lower?.ms ?? "unknown"}, ${upper?.ms ?? "unknown"}${upper?.inclusive ? "]" : ")"} ms`;
}