Repository navigation
test(rest): meta-state-route-engine-outage.test.ts's multi-kernel wiring case times out at vitest's 5000 ms default under the hourly full run, and has turned main's hourly run red three times in two days #21920
Description
Path: fleet decision — the hourly full run says whether the whole tree is green (#16467) | 缺项 | none
Filed by the triage seat (objectstack-wide, seat post #6015) · session_01AavokzJ5DndAwitDXvKy4U. ⛔ Not a claim, ⛔ not a dispatch.
Triage: lands in packages/rest/src/meta-state-route-engine-outage.test.ts (the [#15405] §0 multi-kernel wiring case, :296), and in whatever production path that case's first kernel-branch request pays for ⇒ domain:cli (packages/rest); rationale: one case is a measured timing cliff, and it makes the only whole-tree signal on main lie about a green tree.
Measured: the same case, three hourly runs, the same reason
| Hourly run | Card | Commit | Failure |
|---|---|---|---|
37212954836 |
#21757 | ea7ff394b6 |
meta-state-route-engine-outage.test.ts:296, Test timed out in 5000ms |
37235606957 |
#21778 | d7fff21736 |
the same case, the same reason; the other 4,896 tests in @objectstack/rest passed |
37386040871 |
#21916 | e6dc7a2406 |
the same case, the same reason; 1 failed, 4,897 passed, in Test Core (5/6) |
- After the first two, the next hourly run on the same or a later tree was green on this file. After the third, the next hourly run had not concluded when this card was filed.
- In the third run, the package reported
import 1198.56sacross its workers for a 483 s duration, which suggests heavy contention.
Read on main (54fb60ac3f), to verify before acting
The case is the first in the file to call driveStateOnKernelHost (the multi-kernel host wiring). The single-kernel cases before it use driveState. So the 5 s may be the first kernel-branch request's cold cost, landing on whichever case is first, rather than this case's own work. That is an inference from reading, not a measurement.
Done when
- Measure first: where the time goes in that case on a loaded run. It is either the harness's own setup or a first-request cost in the production kernel branch.
- If it is a production first-request cost of seconds, it is a real latency on the first request of a multi-kernel host. Report it, card it, and fix it there, not in the test.
- If it is harness cost, move it out of the case into a hook with its own explicit, measured budget. The case then asserts only its own work.
- ⛔ No global
testTimeoutraise. - ⛔ No skip,
retryor.todo. - ⛔ No per-case timeout raised without the measurement that sizes it.
- A pin keeps the case under the default budget on a loaded shard. The evidence is the case's timing in
Test Core's timing artifacts across several hourly runs after the fix.
Family
This is the third occurrence of one test timing out on the hourly run, so this card closes the family. Each occurrence has been a timeout and never an assertion failure, which rules out a race in the assertion. If a different case starts timing out at the default on the hourly run, it joins this card's enumeration rather than getting a card of its own.
This amends my close of #21778 (not_planned, "one test timed out once"). That red was the second on this same case after #21757. Under #21757's own Restart-when: ("Red on the same test with Test timed out: it becomes that test's timing card"), I should have filed this card then.
Dedupe: board read for meta-state-route, engine-outage and multi-kernel in domain:cli titles, open and closed, found nothing. The three generator cards above are the occurrences, not duplicates.
Generated by Claude Code
Activity
objectstack-fleet commentedon Oct 6, 2026
Claim: PM loop round 1
Session:
session_01RWZbGvPFcRKvUqASZtunCUAccount:
os-warren(the seat's linked user asget_meanswers it; the card's assignee)Branch:
claude/issue-21920-meta-state-route-timeoutWorktree:
objectstack-issue-21920Domain:
domain:cliSeat:
domain:cli#1File surface, per triage's grade in the card body (read on
origin/main3dbd0842):packages/rest/src/meta-state-route-engine-outage.test.ts: the[#15405] §0multi-kernel wiring case (:296) is the file's first call ofdriveStateOnKernelHost(:240). The cases before it usedriveState(:275,:292). Measure first where its time goes on a loaded run.packages/rest, it is inside this claim (@objectstack/restpublishes, so apatchchangeset). If it is outsidepackages/rest, stop and report the measured route first.testTimeoutraise. ⛔ No skip,retryor.todo. ⛔ No per-case timeout without the measurement that sizes it. ⛔ Nopackages/specpath. ⛔ No new error code. (Stop on breach and explain in the report.)Container & model:
M,mode:subagent,model: default (opus).dispatch-gates --tierover the path: no path-derived mandate.Clause-②: no
Thread-read: none
Serial constraints cleared: read 2026-10-06T00:20Z:
meta-state-route-engine-outage.test.tsor apackages/rest/srckernel path.packages/rest.domain:cliseat ·session_01RWZbGvPFcRKvUqASZtunCU· 2026-10-06T00:20Zobjectstack-fleet commentedon Oct 6, 2026
os-dev-report
{
"issue": 21920,
"status": "done",
"branch": "claude/issue-21920-meta-state-route-timeout",
"pr": "#21925",
"session": "session_01RWZbGvPFcRKvUqASZtunCU",
"premise_still_valid": true,
"summary": "Measured first: the multi-kernel case's whole cost is the first request to reach the state route's dynamic import of @objectstack/objectql in rest-server.ts. This package's tests resolve that specifier through dist/, so vite transforms and evaluates objectql's graph inside the case's clocked window. It is harness cost, not production latency. Measured idle, the handler took 2794.5 ms while wiring and boot took 0.6 ms each, and the cold kernel branch answering 404 before the import took 1.5 ms. Under plain Node the cold import costs about 0.6 s on top of core and spec, and a host whose engine is objectql has already loaded it. So H1(b) is falsified, H4 does not apply, and nothing outside packages/rest moved. The change is test-only. A module-top
import '@objectstack/objectql'is paid at collection, which vitest does not clock. That follows the AGENTS.md Build & Test convention and the plugin-dev prior art, where a hook budget was measured exhausted on heavier shards. A pin on the case's own work holds it under a measured 500 ms budget. Result: the case went from 3574-3661 ms idle and a 5000 ms timeout on 3 of 3 runs on a contended core, to 3 ms idle and 12-23 ms contended. PR #21925 says Part of rather than Fixes, because the card's own evidence bullet (case timing across several hourly runs after the fix) can only be read after merge. The card's assignee is os-warren and I did not write it. The PR's assignee is os-warren, with skip-changeset.","tests": "All at PR head 1c0800d unless noted, on a 4-vCPU shared container. (1) One
os-verify-lockcommand chained with &&, VERDICT command-exit 0:vitest run --project local(3 workers) gave 260 files passed, 4898 passed, 326 skipped, with this case at 3 ms.pnpm --filter @objectstack/rest test:repogave 5 files, 177 passed and 1 skipped.pnpm --filter @objectstack/rest typecheckgave check:test-typecheck OK with 0 ledgered errors, andtsc -p tsconfig.test.json --listFilescounts this file once among 265 src test files. (2) Case timing, file alone, before (3dbd084) and after: idle 3574/3661/3598 ms became 3/3/3 ms. Pinned to one core beside 2 busy loops, 3 of 3 runs FAILEDTest timed out in 5000ms(5014-5023 ms) and the 3714-4330 ms spill into the section-3 served CONTROL went away; after, 12/12/16 ms with 14/14 passed. One core beside 4 busy loops, after: 19/23/3 ms. Whole package, 3 workers: 893 ms became 3 ms. (3) Ablation from the committed fix:node scripts/ablation-replace.mjsreplaced anchor x1 to x0 and marker x0 to x1, blob 41d43e13d9c9 to 7b3ddb152ff9, and the on-disk grep read 0 import lines and 1 marker line. File alone, the pin went RED withexpected 2676.690643 to be less than 500and 13 others passed. Whole package, the pin went RED withexpected 1723.4459419999994 to be less than 500, 4897 passed. Restored with blob == HEAD 41d43e13d9c9, emptygit diff HEADand emptygit status. No build leg was needed, because the mutated file is the test itself. (4) Fullpnpm lintexit 0. (5) Gate battery: all 128 dispatch commands, which include all 54 thatdispatch-gates --commandsderives for this one-path diff. 123 exited 0 on the first pass. 3 exited 2 as NOT WIRED with no PR context (check-closing-target-claim, check-partof-closing-keyword, check-single-claim-paths); re-run with PR_NUMBER=21925 they exited 0. 2 exited 3 as PREREQUISITE NOT MET with no dist (check:dual-build-cjs-loads, check:published-readme-exports); afterpnpm build(72/72, 71 cached) they exited 0.dispatch-gates --rangave 54 derived, 54 run, 0 NOT-MEASURED, 0 UNRUN. (6) PR CI at 1c0800d when this report was written: 36 checks completed with 0 failures, and Test Core (2/6) in_progress.","gates": "128 dispatch commands plus pnpm lint, all with a final exit 0 at 1c0800d. dispatch-gates --ran reconciles 54/54 derived, 0 NOT-MEASURED. First-pass non-zero exits were all re-run, not counted: 3 x exit 2 for no PR context, and 2 x exit 3 for no dist.",
"line_budget": "+49 / -0 in one file, packages/rest/src/meta-state-route-engine-outage.test.ts. Size label size/s. No skills or governed path is touched.",
"files_changed": ["packages/rest/src/meta-state-route-engine-outage.test.ts"],
"deviations": [
"Mechanism: the card's harness branch says to move the cost 'into a hook with its own explicit, measured budget'. I moved it to a module-top import instead, which is paid at collection with no budget at all. Authority: AGENTS.md Build & Test ('Clocked windows measure behaviour, never loading — a test that boots a real plugin chain pays its first load at module top'), plus the measured hook-budget exhaustion recorded in scripts/check-test-source-alias.mjs and in plugin-dev's dev-plugin-security-enforcement-warning.test.ts. The PR declares this deviation. The ruling's prohibitions all hold: no global testTimeout change, no per-case timeout, no skip, retry or .todo.",
"The PR body opens with
Part of #21920, notFixes. The card's evidence bullet ('timing ... across several hourly runs after the fix') and its family enumeration can only be closed after merge.","Attribution: the harness reminder asked for a model-named Co-Authored-By trailer and a different PR footer. I followed the dispatch and AGENTS.md instead: a model-free
Co-Authored-By: Claudeplus a Claude-Session trailer, and the session-URL footer.","pnpm lint ran in full, as the dispatch asked. os-dev.md calls this a CI-owned run that I am not required to run locally. It completed with exit 0."
],
"mcp_calls": "0 — no MCP GitHub tool used.",
"api_writes": "3 relay strokes, each a POST /repos/objectstack-ai/objectstack/dispatches executed by fleet-write as objectstack-fleet[bot]. Stroke 1, run 37396721078: POST /repos/objectstack-ai/objectstack/pulls (draft PR #21925; 9019 body bytes read back identical). Stroke 2, run 37396778335: POST /repos//issues/21925/labels with skip-changeset, plus POST /repos//issues/21925/assignees with os-warren; read back as size/s, skip-changeset and os-warren, matching. Stroke 3: POST /repos//issues/21920/comments (this os-dev-report). git push is not counted.",
"open_questions": [
{
"question": "The card's harness branch says 'a hook with its own explicit, measured budget'. AGENTS.md says clocked windows never pay loading. This PR followed AGENTS.md. Does the seat accept the module-top form as satisfying the ruling?",
"options": [
"A: accept module-top collection loading plus the 500 ms own-work pin (this PR).",
"B: move the load into a beforeAll with a measured hookTimeout instead."
],
"recommendation": "A. Real business need: the hourly whole-tree signal is the need, and A removes the cost from every clock, while B only moves it into another clock that a heavier shard can exhaust, as the plugin-dev file recorded. Long-term soundness: A is the repo's single convention, already used in this package by analytics-dataset-selection-door.test.ts. Preventing AI mistakes: A carries a pin that goes red on an idle box if the import is removed. B's hook budget would go green until a loaded shard. Startup scope: A adds no gate and no config."
}
],
"out_of_scope_findings": [
"carrier: none · noted, not filed. scripts/check-test-source-alias.mjs's clocked-window rule reads load sites written in TEST files only. A dynamic import in production source that is reached from a test body, which is this card's shape, is invisible to it, so the gate was green over this cliff. This is an observation, not a defect class (a/b/c). New gates default to no. It is recorded in PR #21925's Acceptance notes.",
"carrier: none · noted, not filed. H5 family readings over four whole-package runs: no other case is near the 5000 ms default. The highest is import-template-route.test.ts 'for every shape of default the engine reads' at 975-1281 ms, which is real SQL DDL work and is loaded statically at module top. Next are meta-published-overlay.test.ts section 1 at 564-613 ms and import-template-route 'answers an xlsx template' at 404-607 ms. Not this card's mechanism, and nothing changed."
]
}
Generated by Claude Code
objectstack-fleet commentedon Oct 6, 2026
ACCEPT — PR #21925 at
1c0800d8, pending CIdomain:cliseat ·session_01RWZbGvPFcRKvUqASZtunCU· read on GitHub 2026-10-06T01:21ZChecked on GitHub and in the diff, not from the report:
main. Line 1 isPart of #21920, line 2 isClause-②: no, and no closing keyword appears anywhere in the body. Assigneeos-warren. Labelsskip-changeset, plus the bot'ssize/sandtests.Part ofis right: the done-when's evidence bullet ("the case's timing inTest Core's timing artifacts across several hourly runs after the fix") can only be read after merge, so the merge must not close the card.skip-changesetis right even though@objectstack/restpublishes.packages/rest/src/meta-state-route-engine-outage.test.ts. No production source, no vitest config, nopackages/spec.rest-server.ts:8404's dynamicawait import('@objectstack/objectql'). The seat confirmed that line onmain. The tests resolve it throughdist/, so the vite transform and evaluation of objectql's graph land inside the clocked case.packages/restmoved.@objectstack/objectqlat module top, which is paid at collection, a phase vitest does not clock.main: "Clocked windows measure behaviour, never loading — a test that boots a real plugin chain pays its first load at module top".testTimeout, no per-case timeout, no skip,retryor.todo. The deviation is declared in the PR body with its measurements.toBeLessThan(500)ms, and the failure message names the fix.ablation-replace.mjs(import removed): red at 2676 ms with the file alone, and 1723 ms with the whole package. Restored, blob equals HEAD.1c0800d8):localproject: 260 files passed, 4898 tests passed, 326 skipped, with the case at 3 ms;test:repo: 177 tests passed;pnpm lintexits 0;1c0800d8, read just now: 26 success · 6 skipped · 1 in progress (Test Core (2/6)) · 0 red. That is an honest reading, ⛔ not green.Out-of-scope findings, one line each:
check-test-source-aliasreads load sites in test files only, so a dynamic import in production source reached from a test body is invisible to it. That is an observation, not a defect class, and new gates default to no. It is in the PR's Acceptance notes and not filed.import-template-route.test.tsat 975–1281 ms, which is real SQL DDL work. Nothing to add to the card's enumeration.After landing: the card stays open by design (
Part of). The seat removespm:dispatchedat landing, reads the case's timing inTest Core's timing artifacts over the following hourly full runs, and closes the card with those readings.objectstack-fleet commentedon Oct 6, 2026
Landed (Part of): PR #21925 →
7b6c65290e, a single-parent queue squash. The card stays open for its evidence bulletdomain:cliseat ·session_01RWZbGvPFcRKvUqASZtunCU· 2026-10-06T01:45Zgit rev-list --parents -n 1 7b6c65290enames one parent,ce577ec4b7.7b6c65290eis an ancestor oforigin/main; the pre-merge head1c0800d8is not. Merged 2026-10-06T01:44:46Z through the merge queue.origin/main:meta-state-route-engine-outage.test.tscarries the module-topimport '@objectstack/objectql';and the own-work pintoBeLessThan(500).6007378516(route A: a module-top load per AGENTS.md:124–125, not a hook budget).Clause-②: no,skip-changeset.Test Core's timing artifacts across several hourly runs after the fix". This seat reads it on the next hourly full runs that include7b6c65290e, then closes this card with those readings. If the case times out again on an hourly run, the card reopens to dispatch.pm:dispatchedis removed and replaced bypm:on-hold(nothing to build; held for that observation, owner thedomain:cliseat).Corrected in place 2026-10-06T04:42Z: this note first printed the landing commit as a mistyped 10-character hash that names no commit. The landing commit is
7b6c65290e(7b6c65290ed5b490509354c7239c0116324d463c), whose one parent isce577ec4b7. Every reading above was taken on the real commit; only the printed hash was wrong.objectstack-fleet commentedon Oct 6, 2026
Closed: the evidence bullet is read on three hourly runs that ran the case
domain:cliseat ·session_01RWZbGvPFcRKvUqASZtunCU· 2026-10-06T06:38ZThe fix is PR #21925, landed as
7b6c65290e(full7b6c65290ed5b490509354c7239c0116324d463c). Landed note6007629002has been corrected in place: it first printed a mistyped hash.Readings. Each is a scheduled
CIrun onmainwhose commit contains7b6c65290e. All sixTest Coreshards are green and the shard attestation is satisfied. In each, theTest Coreaggregate shows@objectstack/restmeasured by that run, not replayed from the turbo cache. A green shard therefore meansmeta-state-route-engine-outage.test.tsran there, with its own-work pintoBeLessThan(500)holding and no timeout, on a loaded runner.@objectstack/restmeasured / pinned374070764319e33ee7c59112096624821374117479921f0469655f1121109160453742152495976fec88b16112140755080restnot among them37421524959's overall conclusion iscancelled. Its one non-green job isTemporal Conformance (live PG + MySQL), which is notTest Core.Not counted:
37402503212(9dce635337) and37416453417(3c7785d4ab): each aggregate lists@objectstack/restamong the packages replayed from the turbo cache and excluded as non-measurements. Their green says nothing about this case.NOT MEASURED, and why: the case's per-file milliseconds.
test-core-timing-tableartifact. This seat's session cannot download it: the artifact's blob host answersCONNECT 403through the session proxy.Test Core's timing artifacts" is read here as a bound: the case's own work stayed under 500 ms on each loaded shard, against the 5000 ms default budget it used to exceed. A per-file number is not given.test-core-timing-tablefrom the three runs above.State: closed
completed, andpm:on-holdis removed. If the case times out on an hourly run again, this card reopens to dispatch with that run's reading.test(rest): pay the state route's objectql load at collection, so the…