test(web): run the performance-tracks spec on a controllable engine clock - #3598
Merged
Merged
Conversation
…lock The spec's colour and duration assertions were cut against wall-clock `performance.now()` deltas the attribution engine stamps on its records — a wave is `primary` under 16ms, a callback `secondary-light` under 10ms, a hold `error` from `longHolds.infoMs` — so a loaded CI runner crossed a threshold at random (#3594: a two-run drain read `>= 16ms` and the wave came out `primary-dark`). Every test now runs on a `performance.now()` of its own, frozen unless the test advances it inside a compute, a callback, a handler, or while a flight is in the air. Every span's start/end, every record's `handlerMs`, `settledMs`, `totalMs`, `holdMs`, `tailMs`, `durationMs` and `shownMs`, and every `Duration`/`Settled`/`Held`/`Self time` property is asserted exactly against the advances made; the `>=`/`toBeCloseTo`/`- 0.001` tolerances and the real `setTimeout(10)` waits are gone. Each threshold — the wave's 16ms, the callback's 10ms/100ms, the self-time palette's 0.5/10/100ms, and the engine's long-hold verdict at 500ms — is exercised on both sides, at its exact boundary value. No source change: the engine's `now()` reads `performance.now()` on every call and the adapter paints only from the records, so a stand-in on `performance.now` (installed and torn down like the spec's other `performance` stand-ins) is the whole hook. Co-authored-by: Claude via Cursor <noreply@cursor.com>
|
Coverage Report for CI Build 35799447696Coverage remained the same at 72.852%Details
Uncovered ChangesNo uncovered changes found. Coverage RegressionsNo coverage regressions found. Coverage Stats
💛 - Coveralls |
Merging this PR will not alter performance
Comparing 
Footnotes
|
ryansolid
added a commit
that referenced
this pull request
Sep 24, 2026
…ned clock "stays quiet below the hold threshold, and info between the two" raced the wall clock: a 1ms `await` had to settle under `infoMs: 10`, and on the coverage-instrumented CI job (12× slower than a local run) it did not. The engine reads `performance.now()` at the handler's return and at its promise's settle, so the test now owns that clock (#3598's pattern): it stands still unless the handler advances it — 9ms for the quiet side, 30ms for the info side — and both `continuationMs` values are asserted exactly. Real timers still drive the await; only the stamps are the test's. Co-authored-by: Claude via Cursor <noreply@cursor.com>
ryansolid
added a commit
that referenced
this pull request
Sep 24, 2026
…_ASYNC_HANDLER (#3604) * feat(signals): an interaction waits for its handler's promise; UNTRACKED_ASYNC_HANDLER names the dead click no hold could judge `onClick={async () => setResult(await save())}` returns a promise and continues past the interaction frame. The record settled `idle` the moment the handler returned, so the wait the person experienced — the whole round-trip — was invisible to every verdict: no root write before the `await` means no hold opened, and SILENT_HOLD judges holds. `withInteraction` now hands the handler's return value to the engine (`AttributionHooks.interactionEnd(returned)`); a thenable keeps the `InteractionEvent` open until it settles either way, capped at 10s so a promise that never settles cannot pin a record. The record carries `continuationMs` (handler return → settle) and `settledMs` covers it, so a consumer's span spans the wait. Writes in the continuation run with no frame on the stack and stay unattributed; only the duration is claimed. At settle, `UNTRACKED_ASYNC_HANDLER` fires when the handler took no other road: no write before the await (a pending flag or optimistic value is the acknowledgement, and its hold is SILENT_HOLD's to judge) and no `action()` step under the frame (an action's steps stay attributed across yields). Hold thresholds, since it is the same wait; off with `holds: false`. The message carries the two repairs: make the work an action, or write the pending state first. Size: the tier +65 B (the return value through the seam), the engine +384 B (the wait, the cap timer, the check and its text); caps moved with notes. RFC 08 and the skill guide document the code; the plan records D1 and D2 as decided. Co-Authored-By: Claude via Cursor <cursoragent@cursor.com> Co-authored-by: Cursor <cursoragent@cursor.com> * test(signals): judge UNTRACKED_ASYNC_HANDLER's threshold on a test-owned clock "stays quiet below the hold threshold, and info between the two" raced the wall clock: a 1ms `await` had to settle under `infoMs: 10`, and on the coverage-instrumented CI job (12× slower than a local run) it did not. The engine reads `performance.now()` at the handler's return and at its promise's settle, so the test now owns that clock (#3598's pattern): it stands still unless the handler advances it — 9ms for the quiet side, 30ms for the info side — and both `continuationMs` values are asserted exactly. Real timers still drive the await; only the stamps are the test's. Co-authored-by: Claude via Cursor <noreply@cursor.com> * chore(size): re-measure the UNTRACKED_ASYNC_HANDLER engine note at landing 29,408 B against next's 29,018 on the rebased tree (+390 B, 42 B under the 29.45 KB cap); the PR's figures were taken on the pre-#3630 base. Co-authored-by: Claude via Cursor <noreply@cursor.com> --------- Co-authored-by: Claude via Cursor <cursoragent@cursor.com> Co-authored-by: Claude via Cursor <noreply@cursor.com>
ryansolid
added a commit
that referenced
this pull request
Sep 24, 2026
…3635) The "already rejected at hydration" case asserted `waitedMs < 5` on the wall clock. `waitedMs` is the delta between two `performance.now()` reads in the runtime — at boundary registration and when the queued `recover` microtask runs — and on a loaded, coverage-instrumented CI worker that hop read 5.3ms, 7.3ms and 13.3ms today. A failed assertion also skipped the test's own `off()`, leaking the listener into the next test, whose `observed("recovery") === false` check then failed too. `performance.now()` is now a scripted clock (the #3598 pattern): it stands still unless the test moves it, so every duration is asserted exactly — `waitedMs: 0` for the already-rejected case, `30` for the streaming case where the test advances the clock before rejecting, and `renderMs: 2` because rendering the children advances it by 2. The subscription is torn down in `afterEach`, so a failure cannot cascade.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Why
packages/web/test/performance-tracks.spec.tsx(landed with #3580) failed on the unrelated server-only #3594 and passed on rerun: line 415 expected the click wave's colourprimary, gotprimary-dark. The colour isevent.durationMs < 16 ? "primary" : "primary-dark"on the drain'sFlushEvent, anddurationMsis a wall-clockperformance.now()delta the attribution engine stamps — a loaded runner stretched a two-run drain past 16ms.That was the one that fired, but the spec had several assertions cut against measured wall-clock time. Same approach as #3579: drive the clock, assert exact values, exercise each threshold on both sides. No assertion was loosened or deleted; the colour assertion is exact and now has a dedicated both-sides test.
Timing-dependent assertions found (line numbers as of
origin/next)color: "primary"(the flake)FlushEvent.durationMs < 16primary; new test pins 0/15 →primary, 16/40 →primary-darkcallbacks[1].color === "secondary-light"EffectRunEvent.durationMs < 10(an empty callback, but still a measured delta)secondary-light, 10/99 →secondary, 100 →errorcallbacks[1].start >= rerun.at + rerun.totalMs - 0.001start === rerun.at + rerun.totalMswave.start <= rerun.at,wave.end >= callbacks[1].endstart: clicked,end: clicked + 2,end === callbacks[1].endmemoCreate.end >= memoCreate.start,firstCallback.start >= effectCreate.startmounted → mounted + 2, callback ateffectCreate.endtoBeCloseTo(start + handlerMs, 6),toBeCloseTo(at + settledMs, 6)handlerMs/settledMs; the settle span is only painted whensettledMs > handlerMs, which a frozen or coarse clock would not guaranteehandlerMs: 3,settledMs: 8, spans exact,["Handler", "3.00ms"]await setTimeout(10)thenlanded.end - landed.start >= 8,fallback.end - fallback.start >= 8clock.advance(10): flight and fallback are exactlytook → took + 10,["In the air", "10.00ms"],["Shown", "10.00ms"]await setTimeout(10); hold spancolor: "warning"; settletoBeCloseToisLongHold ? "error" : isSilentHold ? "warning" : "tertiary"— a hold whose tail reached the defaultlongHolds.infoMs(500ms) on a stalled runner would painterrorclock.advance(10):holdMs: 10,tailMs: 10,isLongHold(hold) === falseasserted, no"long hold"verdict; new test drives 499ms →warningand 500ms →error(with both verdicts)span.end > span.startsettledMsrequested → requested + 4,["Settled", "4.00ms"]warningbranch assertedbySelfTime(selfMs)cuts at 0.5/10/100ms, unexercisedprimary-light, 0.5/9 →primary, 10/99 →primary-dark, 100 →errorNot timing-dependent (left alone): the
call/frametests build synthetic events fromperformance.now() - 50and assert self-consistently;isSilentHoldhas no threshold (acknowledgements/paint census only); theholds.infoMs/warnMscheck thresholds are set to 0 in the hold tests so the finding fires regardless.Approach
A
beforeEachinstalls a stand-inperformance.now(added to the spec's existingoriginalslist, torn down with the otherperformancestand-ins) returning a value that only moves when a test callsclock.advance(ms)— inside a memo compute, an effect callback, a click handler, or while a flight is in the air. The engine'snow()incore/attribution.tsreadsperformance.now()on every call, and the adapter paints only from the records' stamps, so this is the whole hook: every duration is the sum of the advances the test made, and thresholds are crossed by choice. Real timers are untouched (setTimeoutstill drives the async flights;until()polls onDate.now()).Chosen over
vi.useFakeTimers({ toFake: ["performance"] })because the spec already installs and restores its ownperformancestand-ins and fake-timers would replace the object underneath them.Mutation check: shifting the adapter's
< 16to< 17fails the new wave-colour test at the16 → primary-darkrow and nothing else.Source-side
None needed. No
nowinjection option was required; no public surface touched. No changeset (tests only).Verification
vitest run test/performance-tracks.spec.tsx× 20 in a loop: 20/20 pass (37 tests each).yes > /dev/null× 12 on 10 cores): 10/10 pass.@solidjs/webclient suite: 101 files, 898 tests pass.pnpm --filter @solidjs/web test-types: clean.