Skip to content

test(rest): pay the state route's objectql load at collection, so the multi-kernel case stops timing out on the hourly run - #21925

Merged
objectstack-fleet[bot] merged 3 commits into
mainfrom
claude/issue-21920-meta-state-route-timeout
Oct 6, 2026
Merged

objectstack-fleet[bot] merged 3 commits into
mainfrom
claude/issue-21920-meta-state-route-timeout

Conversation

@objectstack-fleet

Copy link
Copy Markdown
Contributor

Part of #21920
Clause-②: no

What stays open on #21920 after this merges: the card's own evidence bullet, "the case's timing in Test Core's timing artifacts across several hourly runs after the fix", which only post-merge hourly runs can supply, and the card's family enumeration. This PR does not close it.

Measured cause: a harness module load, not a production first-request cost

The [#15405] §0 multi-kernel wiring case (meta-state-route-engine-outage.test.ts:296 on origin/main 3dbd0842) is the file's first case to get past the anonymous-deny gate with a schema. That makes it the first to reach the state route's dynamic await import('@objectstack/objectql') in rest-server.ts. @objectstack/rest's tests resolve that specifier through dist/ (it is in this package's KNOWN_UNALIASED_TEST_IMPORTS row), so the first request to reach that line pays a cold vite transform and evaluation of objectql's whole module graph. That load ran inside the case's 5000 ms clocked window.

All readings below are from a 4-vCPU container. The box was shared with sibling agents, so "idle" means the verify lock was free and the load average was about 1.5. The file-alone runs used vitest run --project local --maxWorkers=1 FILE, plus a JSON reporter for the per-case durations.

Reading Before (3dbd0842) After (1c0800d8)
§0 multi-kernel case, file alone, idle (3 runs) 3574 / 3661 / 3598 ms 3 / 3 / 3 ms (and 4 ms at the final head)
same, the file pinned to one core beside 2 busy loops (3 runs) Test timed out in 5000ms, 3 of 3 (5014-5023 ms) 12 / 12 / 16 ms, 14 of 14 passed
§3 served CONTROL, same 2-busy-loop runs 3714 / 4224 / 4330 ms: the still-running load spilled into the next case that reaches the same line 1 / 9 / 9 ms
§0 multi-kernel case, one core beside 4 busy loops (3 runs) not run 19 / 23 / 3 ms; the file's slowest case is 166 ms
§0 multi-kernel case, whole @objectstack/rest local suite, 3 workers 893 ms 3 ms
vitest's tests total for the file, idle 3.64-3.73 s 60-73 ms

A phase-timed probe (a temporary test file, deleted and never committed) separated the parts of the case. Idle, cold, its parts were:

  • kernelHost() wiring: 0.6 ms
  • RestServer construct plus registerRoutes(): 0.6 ms
  • the handler call: 2794.5 ms

On the cold multi-kernel branch, a request answering 404 before it reaches the import cost 1.5 ms. With import('@objectstack/objectql') paid first, the handler took 1.8-1.9 ms. The import itself cost 2643.6 ms at module top and 2660.2 ms in a test body.

  • H1(a) holds and H1(b) is falsified. The cost is the module load. It is neither the multi-kernel branch nor kernelHost() construction, and it lands on whichever case first reaches that import line.
  • H4 does not apply. This is not seconds of production latency. Under plain Node, a cold import('@objectstack/objectql') of the built package costs 1010-1046 ms alone, and 619 ms on top of the @objectstack/core and @objectstack/spec that rest-server.ts already loads statically. A host whose engine is objectql has the module loaded before its first request anyway. The production call stays as it is: it is dynamic on purpose, because objectql is a devDependency of @objectstack/rest and a host without it degrades to 501.

The fix (test-only)

  1. A module-top side-effect import '@objectstack/objectql'; in the test file. vitest pays it during collection, which it does not clock. The dynamic call in rest-server.ts is unchanged.
  2. A pin on the §0 multi-kernel case: its own work, driveStateOnKernelHost(providerHealthy) timed with performance.now(), must stay under 500 ms. The budget is sized from the readings above:
    • The case's own work measured 3 ms idle and at most 23 ms on a fifth of one core, so 500 ms is about 20x above the worst loaded reading.
    • The load it must never carry measured 893 ms and 1723 ms in whole-package runs and 2677-3661 ms with the file alone. 500 ms is below every one of those, so a regression reads red on an idle box rather than only on a loaded shard.

No global testTimeout change, no per-case timeout, no skip, retry or .todo, and nothing outside packages/rest/src/meta-state-route-engine-outage.test.ts.

Deviation from the card's letter, declared rather than chosen silently

For a harness cost, the card says to move it "into a hook with its own explicit, measured budget". This PR moves it to module top instead, into collection, where no budget applies at all. Two reasons:

  • AGENTS.md § Build & Test states the repo convention: "Clocked windows measure behaviour, never loading — a test that boots a real plugin chain pays its first load at module top; pnpm check:test-source-alias gates it."
  • That gate's header, and packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts, record the measured failure of the hook shape. A beforeAll with hookTimeout 10000 ms took the same kind of load to Hook timed out in 10000ms on heavier queue shards, because every budget the cost is moved into can be exhausted by a heavier shard.

The ruling's intent holds:

  • the cost is out of the case;
  • the case asserts only its own work, against a measured budget;
  • none of the three prohibitions is touched.

This package already follows the same pattern: analytics-dataset-selection-door.test.ts pays @objectstack/spec/api and @objectstack/spec/data at module top for the same reason.

Ablation (one-off, no permanent artifact)

The fix was committed first. Then node scripts/ablation-replace.mjs replaced the anchor import '@objectstack/objectql'; (1 hit, 1 to 0) with a marker comment (0 to 1), blob 41d43e13d9c9 to 7b3ddb152ff9. The on-disk count read 0 import lines and 1 marker line before either leg ran. Both legs were run from the mutated tree:

  • file alone, idle: the pin went red with expected 2676.690643 to be less than 500, and the other 13 cases passed.
  • whole local suite, 3 workers: the pin went red with expected 1723.4459419999994 to be less than 500, with 1 failed and 4897 passed.

Restore was proven by the tool: blob after restore equals the HEAD blob 41d43e13d9c9, and git diff HEAD is empty. git status --porcelain was empty afterwards. The ablation needed no build leg, because the mutated file is the test itself, which vitest reads from source.

Family readings (H5): no second case near the default

These readings come from four runs of the whole @objectstack/rest local suite with 3 workers: before the fix, the ablation, after the fix, and at the final head. The last of those ran beside the gate battery. They list every other case at or above 300 ms:

Case Reading
import-template-route.test.ts "for every shape of default the engine reads" 975 / 1038 / 1281 / 1247 ms
meta-published-overlay.test.ts "§1 serves a RUNTIME-published item…" 564 / 593 / 593 / 613 ms
import-template-route.test.ts "answers an xlsx template…" 404 / 413 / 468 / 607 ms
nine more cases at the final head, in the import-* files and rest-data-number-value.test.ts 309-380 ms

I read the files of the first three rows. They import their engines statically at module top, so no first load is paid inside their clocks. "For every shape of default" spends its time on real work: SQL DDL across many objects. I did not read the files of the last row. Every reading is at or below 26% of the 5000 ms default, so this PR changes nothing else.

Tests and gates

All of these ran at 1c0800d8, the PR head, as one command chained with && under the verify lock, which reported VERDICT command-exit 0:

  • @objectstack/rest local suite, vitest run --project local, 3 workers: 260 files passed, 4898 passed and 326 skipped. The §0 multi-kernel case took 3 ms.
  • pnpm --filter @objectstack/rest test:repo: 5 files passed, 177 passed and 1 skipped.
  • pnpm --filter @objectstack/rest typecheck: check:test-typecheck: OK with 0 ledgered errors. The test layer is compiled under tsconfig.test.json, and --listFiles counts this file once among 265 src/**/*.test.ts files.

The gate battery is the dispatch's 128 commands, a superset of the 54 that dispatch-gates.mjs --commands derives for this one-path change. Its results are in the report on the card. check:closing-target-claim reads PR context, so it is NOT MEASURED before the PR exists.

Acceptance notes

  • scripts/check-test-source-alias.mjs's clocked-window rule reads load sites written in TEST files. It does not read a dynamic import written in production source and reached from a test body, which is how this one landed in a clocked window with the gate green. This is recorded as an observation only. No gate is proposed, since new gates default to no, and nothing is filed. Carrier: none.

Generated by Claude Code

claude added 3 commits October 6, 2026 00:37
… the multi-kernel case

The first case to get past the gate with a schema paid the cold load of
`@objectstack/objectql` that `GET /meta/object/:name/state/:field` reaches
through a dynamic import: 3.6 s of the 5000 ms budget idle, and a timeout on
every run confined to one contended core. A module-top import moves that cost
into collection, which vitest does not clock.

Claude-Session: https://claude.ai/code/session_01RWZbGvPFcRKvUqASZtunCU
Co-Authored-By: Claude <noreply@anthropic.com>
… ms budget

The case is the file's first to reach the state route's objectql import, so it
is where a load moved back into a clocked window would land. Its own work
measures 3 ms idle and at most 23 ms on a fifth of one core; the load measured
893-3661 ms. A 500 ms budget reads that regression red on an idle box.

Claude-Session: https://claude.ai/code/session_01RWZbGvPFcRKvUqASZtunCU
Co-Authored-By: Claude <noreply@anthropic.com>
@github-actions github-actions Bot added the size/s label Oct 6, 2026
@objectstack-fleet objectstack-fleet Bot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Oct 6, 2026
@github-actions github-actions Bot added the tests label Oct 6, 2026
@github-actions

github-actions Bot commented Oct 6, 2026

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

Nothing in this diff resolved to a documentable surface (no symbol, route or SDK anchor derived from 0 changed package(s)), so this run has no opinion about the docs.

What this run could not see

Coarse fallback — 0 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json faf8dce482c862311f844ada6b70f515378dfd54 → packageMentionDocs.

@objectstack-fleet
objectstack-fleet Bot marked this pull request as ready for review October 6, 2026 01:23
@objectstack-fleet
objectstack-fleet Bot enabled auto-merge October 6, 2026 01:23
@objectstack-fleet
objectstack-fleet Bot added this pull request to the merge queue Oct 6, 2026
Merged via the queue into main with commit 7b6c652 Oct 6, 2026
40 checks passed
@objectstack-fleet
objectstack-fleet Bot deleted the claude/issue-21920-meta-state-route-timeout branch October 6, 2026 01:44
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/s skip-changeset PR has no user-facing published change; bypasses the changeset gate tests

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants