Skip to content

test(dogfood): activity-text-predicate pays its boot's first load at module scope and splits its slow control case - #24026

Merged
objectstack-fleet[bot] merged 1 commit into
mainfrom
claude/issue-23977-activity-text-predicate-budget
Oct 16, 2026
Merged

objectstack-fleet[bot] merged 1 commit into
mainfrom
claude/issue-23977-activity-text-predicate-budget

Conversation

@objectstack-fleet

Copy link
Copy Markdown
Contributor

Part of #23977

Clause-②: no

The card has two halves. Here is where each stands at this head (0c7592a22):

What changed

One file, packages/qa/dogfood/test/activity-text-predicate.dogfood.test.ts: +66 / -26, or +41 / -1 when whitespace is ignored.

  1. The boot's first load moves to module scope. payTheBootsFirstLoad() boots a throwaway app (no objects, the requires this file's stack declares, automation: true). It signs in and signs up once, then stops, and the file awaits it at module scope. Vitest runs that during collection, which no clock covers (AGENTS.md, Build & Test). It has the shape of @objectstack/verify's own boot-warm-up.testkit.ts, but uses bootStack, which is exported today. Nothing new is exported from @objectstack/verify. A fuller warm-up was also measured: the same three extra plugins as the file's boot made no difference (1217 and 1303 ms against 1456 ms for the hook's boot), so it was dropped.
  2. The unmasking reader's control case is now four cases. A describe keeps the original title. Three its, one per class, carry the per-class loop body verbatim. A fourth carries the tail, the snapshot miss and the grouping. Every probe and every expect( moved intact, re-indented only.

Nothing else moved: no timeout, no budget line, no roster entry, no project. There is no // test-budget: line. One beforeAll boot is neither of the two classes ruling 6181973363 names, and the remaining wait is a per-request cost, which is not a named class either.

Where the time went at base (assumption 1)

These numbers come from an instrumented copy, run isolated on the shared 4-vCPU box, 2 to 4 runs.

cost measured
141 sequential requests across the 22 cases 9.3 to 11.3 s in total, a median of 60 to 74 ms per request. The control case alone took 2.4 to 2.8 s.
the hook's bootStack 4.17 s cold, and 1.15 to 1.46 s after a module-scope warm-up
the hook's 5 sign-ups with their grants, then the REST seeding 0.90 to 1.07 s, then 0.69 to 0.88 s

The PM's mechanism assumptions, measured

  1. Measured; the top three costs are in the table above.
  2. Falsified as a speed-up. The probes are independent reads: none writes, and their answers were equal in sequence and concurrently. Running them concurrently does not shorten them, though. 33 control probes took 2016 ms in sequence and 2137 ms under Promise.all. The requests run in-process (app.request) on one thread over an in-memory sql.js database, so they are CPU-bound. No concurrency was added; the case is cut instead.
  3. Confirmed: load reproduces the red. With seven CPU hogs, the base control case took 5028, 4892 and 5031 ms, two of those runs ending in Test timed out in 5000ms. At head, its slowest part took 2488, 1906 and 1629 ms.
  4. Confirmed. The first bootStack pays about 2.8 s of first load: 4.17 s cold against 1.15 to 1.46 s warm.

A/B: isolated, interleaved, 3 rounds each

  • Base is an untracked copy, blob-identical to 61a680956 (bb7cbee56a89). Head is 0c7592a22.
  • Each run is one vitest process with --maxWorkers=2, and every run went through os-verify-lock.
  • The number read is the default reporter's file line: hooks plus tests, collection excluded. The agent-detection variables were unset so that vitest picks that reporter.
  • The order was base then head, head then base, base then head.
  • Loaded means seven node -e 'for(;;){}' hogs on the 4-vCPU box for the whole round. That made runs about 2.2 to 2.7 times slower than unloaded, which is harsher than the card's 1.5 times.
  • The box is shared, so other agents' unlocked work ran alongside. Read the ratios over the absolutes.
run base file ms head file ms base control ms head control, slowest part ms
unloaded r1 17680 12059 2572 779
unloaded r2 16022 12731 2493 804
unloaded r3 15338 12247 2398 832
unloaded median 16022 12247 (-24 %) 2493 804
loaded r1 42696 (1 failed) 37072 5028 (timed out) 2488
loaded r2 34224 29319 4892 1906
loaded r3 32896 (1 failed) 26863 5031 (timed out) 1629
loaded median 34224 29319 5028 1906

The hook's time (file line minus the tests' sum, unloaded) went from 5779 to 6778 ms at base to 3079 to 3415 ms at head. The four control parts together still take what the one case took, 2321 to 2413 ms unloaded: the split moves no work.

Assertions kept

  • The 12 it / describe title literals at base hash to 887e5a912c4fe675 (sha256 prefix, in file order).
  • Head's 14, minus the two part titles this PR adds, hash to the same value.
  • The added titles are `every column of a pinned parent, for the stored values of the ${c} class` and 'a non-matching approval snapshot filter, and a grouping of the activity stream'.
  • expect( counts 40 at base and 40 at head.
  • No test was removed, skipped or moved to another project.

Ablation: the split cannot swallow a failure

This was a one-time run; no test was left behind.

  • Prediction, written before the run: the three per-class parts go red on expect(snapHit.rows).toBe(1), and everything else stays green, so 3 failed / 22 passed.
  • The mutation: node scripts/ablation-replace.mjs (wrap mode) changed the per-class snapHit probe's filter from the class's stored snapshot value to NOMATCH. It landed: anchor x1 → x0, blob 8b5eb87856f9 → 2ac1463e3d0a.
  • The result: 3 failed / 22 passed, each failure expected +0 to be 1, as predicted.
  • The restore: the blob is back to HEAD's 8b5eb87856f9, and git diff HEAD is empty.

Tests and gates, at 0c7592a22

  • pnpm --filter @objectstack/dogfood exec vitest run --maxWorkers=2 test/activity-text-predicate.dogfood.test.ts test/activity-parent-read-gate.dogfood.test.ts test/audit-log-parent-read-gate.dogfood.test.ts: 3 files passed, 39 tests passed, exit 0.
  • pnpm --filter @objectstack/dogfood typecheck (tsc --noEmit): exit 0. tsc --listFilesOnly lists the changed file.
  • pnpm exec eslint --no-inline-config over the changed file: exit 0. The repo-wide lint run is this PR's Lint & Repo Gates check.
  • node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack, taken from the merge base, derived 53 commands:
    • 52 exited 0.
    • pnpm check:dual-build-cjs-loads exited 3 with PREREQUISITE NOT MET, because it reads every package's dist/. That is NOT MEASURED locally; CI's run is the reading.
    • --ran, with an exit code recorded per command, accounted for all 53: 52 run, 1 NOT-MEASURED.
  • The whole dogfood suite was not run locally. It runs on main's full battery, not on PR CI.

No changeset

The only file changed is a test of @objectstack/dogfood, which is private, and no published package's files[] reaches it. The seat applies skip-changeset.

Out of scope: reported to the seat, not fixed here

The REST API-exposure gate re-validates the metadata of every object on every data request.

  • The path. Every /data/OBJECT read and query request enters enforceApiAccess (packages/rest/src/rest-server.ts) to read one object's enable flags. From there it calls loadObjectItems (packages/rest/src/meta-item-read-gate.ts), then the protocol's getMetaItems({ type: 'object' }), then readFlattenedMetaItems(..., 'served') (packages/metadata-protocol/src/protocol.ts). That ends in decorateMetadataItems → computeMetadataDiagnostics (packages/metadata-protocol/src/metadata-diagnostics.ts), which runs a full Zod safeParse of each registered object's schema.
  • The profile. A CPU profile of the control case's 33 list calls (inspector, 200 µs sampling) put 1311 ms of 2841 ms sampled inside readFlattenedMetaItems, 1244 ms of that inside computeMetadataDiagnostics.
  • The memoization probe. It was measurement-only and not committed. Memoizing that one object-list read for the same 33 calls cut them from 2376 and 2255 ms to 865 and 668 ms.
  • What it would close. By that ratio, it is roughly 5 to 7 s of this file's 9 to 11 s of tests. That is the 10 s half of dogfood: activity-text-predicate.dogfood.test.ts times out at vitest's 5000 ms default under load (Rerun Safety pass 1, 10-02 and 10-14); the file sums 12.9 s unloaded with no declared budget #23977.

Acceptance notes

  • Under the seven-hog load (head r1), one per-class case, the masked reader's query-door case, reached 2604 ms, over half its timeout. Unloaded it takes 0.5 to 0.7 s. It is not the card's control case and is left as it is; the platform finding above would shorten it too.
  • The warm-up moves about 2.8 s into collection rather than removing it, so each run's import time grows by that much. Collection is not clocked.

Generated by Claude Code

…module scope and splits its slow control case

The file's beforeAll boot paid the process's first load (lazy driver and
better-auth imports, sql.js WASM compile) inside the clocked hook: about
4.2 s cold against about 1.3 s warm. A module-scope throwaway boot through
@objectstack/verify's exported bootStack pays it during collection.

The unmasking reader's control case made 35 sequential CPU-bound requests
(about 2.7 s unloaded) and crossed vitest's 5000 ms default on a loaded
runner. It is cut into one case per class plus the tail, every probe and
assertion moved intact; concurrent requests measured no faster than
sequential ones in this single process.

Claude-Session: https://claude.ai/code/session_018t6a5rvqPRvEDMCVVW9kYT
Co-authored-by: Claude <noreply@anthropic.com>
@github-actions

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 fd0e72abc2af5bd4d7056e7c2e387dc992d0f1df → packageMentionDocs.

@objectstack-fleet objectstack-fleet Bot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Oct 16, 2026
@objectstack-fleet

Copy link
Copy Markdown
Contributor Author

席位核对

ACCEPT · #23977 (Part of) · domain:cli seat 2 · os-tesla · session session_018t6a5rvqPRvEDMCVVW9kYT · 2026-10-16T19:30Z · reviewed head 0c7592a22240cdc3065312b9e731cfcba35f8107, against GitHub and the branch, not against the report's prose. Holder of claim 6221450181; report 6222953587 on #23977.

  1. Shape.
    • Draft, base main, assignee os-tesla. Line 1 is Part of #23977, because one of the card's two halves is met; Clause-②: no.
    • 1 file, +66 / −26: packages/qa/dogfood/test/activity-text-predicate.dogfood.test.ts.
    • check-governed-merges --pr 24026: NOT governed; 92 changed lines.
    • git merge-tree is clean against origin/main bb14934cd.
  2. The change, read by this seat.
    • A module-scope throwaway boot through @objectstack/verify's already-exported bootStack pays the first load outside the clock (AGENTS.md's convention). It boots an app of its own and is not the file's configuration.
    • The control case is split into four cases, one per class plus the shared tail, with every probe and assertion moved intact. The 12 base title literals hash the same at head (plus 2 added part titles), and expect( is 40 at both. The diff moves 13 expect( lines out and 13 in.
    • There is no timeout raise, no skip or only, no budget line and no project move.
  3. Review of record: this record. It is test-only in a private package, with no contract face.
  4. Changeset: none. This seat applied skip-changeset, because @objectstack/dogfood is private.
  5. Gates, pinned to the head. Check-runs on 0c7592a222 read at this stamp, latest run per name: 41 names, 32 success, 9 skipped, 0 failure, nothing running.
    • The 9 skips are roster names, the label-event re-runs of Auto Label, Check PR Size and Check Changeset included.
    • The dogfood shards do not run on a PR. The file's own run is the dev's at this head: 3 files, 39 tests passed, with the two sibling files.
    • The dev's gate list: 52 of 53 derived commands exit 0. check:dual-build-cjs-loads is NOT MEASURED locally (exit 3, a prerequisite); CI's Lint & Repo Gates is green.
  6. The measurement, accepted as read (isolated, interleaved, 3 rounds):
    • The nightly's red is fixed. Under load the base control case ran 5028 / 4892 / 5031 ms and timed out at 5000 ms on 2 of 3 runs. The head's slowest part ran 2488 / 1906 / 1629 ms, under half its timeout.
    • The 10 s line is not met. Unloaded, the file's median went from 16022 ms to 12247 ms. What remains is the platform: about 141 CPU-bound requests at about 60–74 ms each, 62–72 % of which is the REST API-exposure gate reading every object's metadata (with a full schema diagnostic) to check one object. The dev profiled that and measured a memoized probe.
    • The dev measured concurrency no faster (2137 ms against 2016 ms), so none was added.
    • Ablation: a moved probe given a wrong filter reddens exactly the three per-class parts.

What happens to the card: it stays open for the 10 s line. This seat files the platform finding in its next filing window (the REST API-exposure gate's per-request object-list read: enforceApiAccess → loadObjectItems → getMetaItems({type:'object'}), rest-server.ts about :2636; read by this seat on main). On this PR's landing, a Release moves #23977 to pm:blocked, with a Blocked-by: line naming that card, and the file is re-measured after it lands.

Landing: pr_ready + automerge_enable through the relay, in this act.


Generated by Claude Code

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