perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Add copy buttons to all
 blocks\n(function() {\n function addCopyButtons() {\n document.querySelectorAll('pre code').forEach(function(codeBlock) {\n if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;\n codeBlock.parentElement.setAttribute('data-copy-added', 'true');\n \n var btn = document.createElement('button');\n btn.textContent = 'Copy';\n btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';\n btn.onmouseover = function() { this.style.opacity = '1'; };\n btn.onmouseout = function() { this.style.opacity = '0.7'; };\n btn.onclick = function() {\n navigator.clipboard.writeText(codeBlock.textContent).then(function() {\n btn.textContent = 'Copied!';\n setTimeout(function() { btn.textContent = 'Copy'; }, 1500);\n });\n };\n codeBlock.parentElement.style.position = 'relative';\n codeBlock.parentElement.appendChild(btn);\n });\n }\n \n addCopyButtons();\n \n // Re-run on dynamic content\n var observer = new MutationObserver(addCopyButtons);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Add Copy Buttons to Code Blocks");
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Force GitHub README to respect dark mode\n(function() {\n var style = document.createElement('style');\n style.textContent = '\n .markdown-body {\n color-scheme: dark light;\n }\n .markdown-body pre { background: #161b22 !important; }\n .markdown-body code { background: rgba(110, 118, 129, 0.4) !important; }\n .markdown-body table th, .markdown-body table td { border-color: #30363d !important; }\n .markdown-body img { background: #0d1117; }\n .markdown-body blockquote { border-left-color: #8b949e; }\n .markdown-body hr { border-color: #30363d; }\n ';\n document.head.appendChild(style);\n})();", "GitHub Dark Mode README Fix"); } } catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Highlight search terms from Google/DuckDuckGo/Bing referrer\n(function() {\n var ref = document.referrer;\n var terms = [];\n \n if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) {\n var url = new URL(ref);\n var q = url.searchParams.get('q') || url.searchParams.get('p');\n if (q) {\n terms = q.split(/\\s+/).filter(function(t) { return t.length > 2; });\n }\n }\n \n if (terms.length === 0) return;\n \n var style = document.createElement('style');\n style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }';\n document.head.appendChild(style);\n \n function highlight(node) {\n if (node.nodeType === 3) { // text node\n var text = node.textContent;\n var found = false;\n terms.forEach(function(term) {\n var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\\]\\\\]/g, '\\\\') + ')', 'gi');\n if (regex.test(text)) {\n found = true;\n var frag = document.createDocumentFragment();\n var parts = text.split(regex);\n parts.forEach(function(part, i) {\n if (i % 2 === 0) {\n frag.appendChild(document.createTextNode(part));\n } else {\n var span = document.createElement('span');\n span.className = 'userscript-highlight';\n span.textContent = part;\n frag.appendChild(span);\n }\n });\n node.parentNode.replaceChild(frag, node);\n }\n });\n } else if (node.nodeType === 1 && node.childNodes) { // element\n var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT'];\n if (!skipTags.includes(node.tagName)) {\n Array.from(node.childNodes).forEach(highlight);\n }\n }\n }\n \n highlight(document.body);\n \n // Re-highlight on dynamic content\n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1 || node.nodeType === 3) highlight(node);\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Highlight Search Terms"); } } catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Strip utm_, fbclid, gclid, etc. from all links on page\n(function() {\n var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content',\n 'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid',\n 'ref', 'ref_src', 'source', 'medium', 'campaign'];\n \n function cleanUrl(url) {\n try {\n var u = new URL(url, window.location.origin);\n var changed = false;\n trackingParams.forEach(function(p) {\n if (u.searchParams.has(p)) {\n u.searchParams.delete(p);\n changed = true;\n }\n });\n return changed ? u.toString() : url;\n } catch (e) {\n return url;\n }\n }\n \n function cleanLinks() {\n document.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n \n cleanLinks();\n \n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1) {\n if (node.tagName === 'A') cleanLinks();\n node.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Remove Tracking Parameters from Links"); } } catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); } })(); (function(){ try { var __m = "youtube.com"; var __re = new RegExp('^' + "youtube\\.com" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Auto-enable theater mode on YouTube\n(function() {\n function tryTheater() {\n var btn = document.querySelector('button[aria-label=\"Theater mode\"], ytd-player #player button[title=\"Theater mode\"]');\n if (btn && !btn.classList.contains('activated')) {\n btn.click();\n }\n }\n \n // Try immediately\n tryTheater();\n \n // Try after navigation (SPA)\n var lastUrl = location.href;\n setInterval(function() {\n if (location.href !== lastUrl) {\n lastUrl = location.href;\n setTimeout(tryTheater, 500);\n }\n }, 1000);\n \n // Also try on player load\n var observer = new MutationObserver(tryTheater);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "YouTube Theater Mode Default"); } } catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Remove or un-stick sticky/fixed headers that block content\n(function() {\n function unstick() {\n document.querySelectorAll('header, nav, [role=\"banner\"], .header, .navbar, .sticky, .fixed-top, [style*=\"position: fixed\"], [style*=\"position:sticky\"]').forEach(function(el) {\n if (el.style.position === 'fixed' || el.style.position === 'sticky' || \n getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') {\n el.style.position = 'static';\n el.style.top = 'auto';\n el.style.zIndex = 'auto';\n }\n });\n }\n \n unstick();\n \n var observer = new MutationObserver(unstick);\n observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] });\n})();", "Kill Sticky Headers"); } } catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Universal Dark Mode - works on any site\n(function() {\n var enabled = true;\n \n function applyDarkMode() {\n if (!enabled) return;\n \n // Create style element if it doesn't exist\n var style = document.getElementById('universal-dark-mode-style');\n if (!style) {\n style = document.createElement('style');\n style.id = 'universal-dark-mode-style';\n document.head.appendChild(style);\n }\n \n // Dark mode CSS - inverts colors but preserves images/video\n style.textContent = '\n /* Invert everything except media */\n html {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #1a1a2e !important;\n }\n \n /* Restore images, videos, iframes, canvas */\n img, video, iframe, canvas, svg, picture, [style*=\"background-image\"] {\n filter: invert(1) hue-rotate(180deg) !important;\n }\n \n /* Preserve specific elements that should not be inverted */\n .no-dark-mode, .no-dark-mode *,\n [data-theme=\"light\"], [data-theme=\"light\"],\n .ace_editor, .ace_editor *,\n .CodeMirror, .CodeMirror *,\n .monaco-editor, .monaco-editor *,\n .markdown-body pre, .markdown-body pre *,\n .highlight, .highlight *,\n pre code, pre code * {\n filter: none !important;\n }\n \n /* Fix common UI elements */\n .modal, .popup, .dropdown-menu, .tooltip, .popover {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #2d2d44 !important;\n border-color: #444 !important;\n }\n \n /* Scrollbars */\n ::-webkit-scrollbar { background: #1a1a2e !important; }\n ::-webkit-scrollbar-thumb { background: #444 !important; }\n ::-webkit-scrollbar-thumb:hover { background: #555 !important; }\n \n /* Selection */\n ::selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ';\n }\n \n function removeDarkMode() {\n var style = document.getElementById('universal-dark-mode-style');\n if (style) style.remove();\n }\n \n // Toggle with Alt+Shift+D\n document.addEventListener('keydown', function(e) {\n if (e.altKey && e.shiftKey && e.key === 'D') {\n e.preventDefault();\n enabled = !enabled;\n if (enabled) {\n applyDarkMode();\n console.log('[Universal Dark Mode] Enabled');\n } else {\n removeDarkMode();\n console.log('[Universal Dark Mode] Disabled');\n }\n }\n });\n \n // Apply on load\n applyDarkMode();\n \n // Re-apply on dynamic content\n var observer = new MutationObserver(function(mutations) {\n if (enabled && !document.getElementById('universal-dark-mode-style')) {\n applyDarkMode();\n }\n });\n observer.observe(document.head, { childList: true });\n \n console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle');\n})();", "Universal Dark Mode"); } } catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); } })(); })();
Skip to content

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock) - #14584

Merged
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile
Sep 2, 2026
Merged

perf(pm): memoise the source maskers dispatch-gates re-runs per family (843s to 303s under the verify lock)#14584
baozhoutao merged 2 commits into
mainfrom
claude/issue-14521-dispatch-gates-selftest-profile

Conversation

@claude

@claudeclaudeBot commented Sep 2, 2026

Copy link
Copy Markdown
Contributor

Fixes#14521

check:pm-dispatch-gates was the lock holder for five consecutive os-verify-lock.sh
queue timeouts on the card that filed this. Measured first, as the triage asked, and the
answer is one line: discovery masks each gate source about twelve times per pass, and
the battery pays for that ninety-plus times over.
The maskers are now memoised on their
input string. No family is dropped, no self-test case is dropped, no assertion is
weakened, and the 540 s budget in os-verify-lock.sh is untouched.

BEFORE / AFTER — the profile

Both columns are the same battery, on the same box, through the same entry point. Every
timing run was detached, per check-dispatch-gates.mjs's own header.

Lock hold time — the way the problem was found (triage rule 5)

Shared-box seconds on a 4-core container; the load average is the one printed at the end
of each run. The last two rows are the pair to read: same base commit, same box, only
the patch differs.

runtreeholdwaitedload avg at endrc
before153d368921, unpatched (profiling preload attached)804 s536 s1.200
before253d368921, unpatched, clean816 s232 s2.600
basecmp7286dd58e, unpatched, clean843 s23 s1.070
after17286dd58e + this patch (profiling preload attached)303 s324 s4.470
after2e5fa9d54a (merged) + this patch, via pnpm check:pm-dispatch-gates293 s196 s1.430

843 s to 303 s on the identical base — 2.78x — and the faster run was the one taken
under the heavier load.
Two BEFORE readings on the previous base bracket it at 804 s and
816 s, and the 804 s vs 816 s pair also says the profiling preload costs nothing readable:
the instrumented run was the faster of the two.

⚠️ Idle-versus-loaded was asked for and cannot be delivered honestly: the box is shared and
never idle. What is above is what the box gave, with its load figures attached, rather than
an invented idle number.

The fleet already recorded the BEFORE population

/tmp/os-heavy-verify.lock.ledger — 445 records over 26 h 48 m — names this family in 25
rows, and it is the ledger's largest single consumer of lock-seconds by a factor of six:

 8365s total 13 run(s) pnpm check:pm-dispatch-gates
2078s total 4 run(s) NODE_OPTIONS=--max-old-space-size=4096 pnpm check:pm-dispatch-gates
1599s total 3 run(s) node scripts/pm/check-dispatch-gates.mjs
1942s total 11 run(s) pnpm --filter '@objectstack/lint^...' build ... the next one down

Of those 25 rows, 23 acquired and 2 are queue-timeout at the 540 s budget — the card's
symptom, in the ledger. The 23 holds run 517 s to 842 s, and they are ordered: the four
earliest are 517-521 s, the eight latest are 770-842 s. So the card's "500-900 s" is right,
and the drift inside that range is real rather than noise.

One correction to the triage's baseline

The triage reads 534.5 s out of os-verify-lock.sh:133-134. That figure is rank 1 plus
rank 2
; docs/audits/2026-08-verify-lock-gate-routing-measurement.md:51 measures
check:pm-dispatch-gatesalone at 305.5 s. Against that, the observed 800 s-plus is
~2.7x the documented baseline for this one family, not ~1.6x. Nothing in the scope rules
moves — the correction makes the growth larger, not smaller. That audit is a dated reading
and is left exactly as it is; this is a new reading and it lives here.

Where the 803.9 s went — per case, not a total

From the instrumented before1 run. A case's cost is the wall time between the previous
verdict line and its own, i.e. everything the battery did to decide it; that is the only
attribution a stream of verdict timestamps supports. The AFTER column is the same case in
after1.

#casebeforeaftersaved
1a convention-triggered card is really convention-triggered62.0 s26.8 s35.2 s
2all three ratchets are still discovered with hints, so nothing below is vacuous41.8 s8.7 s33.1 s
3the seam card still derives at all32.3 s13.5 s18.8 s
4--commands answers32.0 s13.7 s18.3 s
5a record that is --commands output copied verbatim reconciles GREEN and exits 031.7 s12.6 s19.1 s
6--json puts a single parseable document on stdout31.2 s13.2 s18.1 s
7a run whose surface ALREADY carries a changeset answers at all31.2 s13.8 s17.4 s
8dropping ONE line from that record exits 1 — a verdict a report cannot paraphrase31.0 s12.8 s18.2 s
9the DEFAULT run answers at all30.9 s13.6 s17.3 s
10the published harvest of the pasted block no longer yields the CI-measured command30.7 s12.3 s18.5 s

Over the 1216 cases present in both profiled runs: 760.2 s to 285.7 s. The top 20 cases
carry 73.3% of the BEFORE total, and every one of them is a case that either spawns the
tool's own CLI or calls discoverFamilies().

Child processes — 58% of the run, and the count does not move

before1after1
spawnSync calls216216
self-spawns of this tool's own CLI28 calls, 465.1 s28 calls, 196.8 s
git (fixture repos, ls-files)184 calls, 2.3 s184 calls, 3.5 s
everything else4 calls, 0.2 s4 calls, 0.2 s
child-process total467.7 s (58.2% of the run)200.5 s

The counts are identical on both sides. That is the point: nothing was removed, each of the
28 self-spawns just stopped paying for the same masking a dozen times. Each one costs
16.6 s before and 7.0 s after.

Inside one discoverFamilies() call — the V8 profile that names the defect

201 families, 196 distinct gate sources, 11.8 MB of source. Self time, attributed to the
nearest frame declared in dispatch-gates.mjs:

frameselfshare
maskSelfTests4.54 s31.7%
anchoredReadTargets1.55 s10.8%
spawnedProgramTargets1.24 s8.7%
garbage collector0.97 s6.8%
extractWatchHints0.92 s6.5%
selfTestOnlyCallables0.87 s6.1%
firstPartyImportTargets0.84 s5.9%
payloadEnvDependence0.80 s5.6%
packageManifestTargets0.79 s5.5%
everything else1.80 s12.4%
total14.32 s

Six of those frames are the six analysers discoverFamilies calls on the same source
string, in one pass of its per-family loop
— and every one of them re-derives the masked
body from scratch. Two of them do it twice (they mask, then hand the masked text to
anchoredReadTargets, which masks again). One source therefore pays maskComments about
seven times and maskSelfTests about five, per discovery, for bytes that cannot have
changed in between.

That is the triage's own target, verbatim: repeated filesystem walks and work that belongs
outside a per-family loop.

The change

scripts/pm/dispatch-gates.mjs only — 74 insertions, 9 deletions, one new module-body
block and nine call sites rewritten to go through it.

Both maskers are pure functions of their input string, so they are memoised on it, behind a
cache bounded by bytes rather than entries (the gate set is ~12 MB and fits whole, so
repeated discoveries in one process reuse it; a tracked-corpus sweep evicts oldest-first
instead of growing without limit). A memo over a pure function is observationally identical
to calling through, and JavaScript strings are immutable, so one caller cannot edit the
shared result under another. A non-string argument bypasses the cache entirely, so a memo
never becomes the thing that decides what a masker does with one.

Unit cost of a single discoverFamilies() call on this tree, three consecutive calls each
way:

before 13616 / 13432 / 14270 ms
after 4923 / 2640 / 2683 ms ... 2.8x cold, 5.1x warm

The warm number is why the in-process half improves at all: the battery calls
discoverFamilies() about fifteen times.

⛔ Not done, deliberately, and each is a triage rule: no family removed, no case removed, no
assertion relaxed (rule 3); scripts/pm/os-verify-lock.sh not touched and the 540 s budget
not raised (rule 4); docs/audits/2026-08-verify-lock-gate-routing-measurement.md not
rewritten; no workflow changed. Cases were not parallelised — the profile did not need
it once the repetition was gone, and a flaky parallel battery is worse than a slow serial
one.

Byte-identical proof

Both trees at base 7286dd58e, the only difference being this patch. basecmp is a
detached worktree at that commit; the run is the same battery through the same lock.

artifactunpatchedpatcheddiff
verdict set (every streamed check/cross line, sorted, timestamps stripped)1241 cases, 1241 pass, 0 fail1241 cases, 1241 pass, 0 failempty
battery's own summary linedispatch-gates self-test: 1240 cases pass.identical
discovered-family list (key, resolved files, hints, reads, selfTest, direct, filter, workflows — sorted)202 families202 familiesempty
runner exit code00

Control, so the empty diffs mean something: two BEFORE runs of the unpatched battery on the
same tree (before1, before2) also produce a byte-identical verdict set, so the
comparison above is measuring the patch and not run-to-run drift.

Gates

Derived on the real diff with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack
(15 families; the tool read the change set from git itself), and the union was run at
e5fa9d54a — the merged head this branch now carries. Fourteen exit 0; the fifteenth,
node scripts/check-test-completeness.mjs, exits 3 — PREREQUISITE NOT MET, which its
own text calls NOT MEASURED and not a finding: it grades a saved turbo run test log and
there is none locally. --ran reconciles the union: 15 derived, 15 run, 0 UNRUN, exit 0.
Per-gate exit codes are in the report comment on #14521.

Declared: the fourteen scripted gates were run off the verify lock. That is what the
lock does today rather than a narrowing — its own header records that routing gate runs
through it was measured one-directional and refused, and --status prints check:* gate
scripts among the work it "does NOT see". The battery itself, which is genuinely heavy, went
through the lock every time, which is where the hold-time table above comes from.

Scripts-only, nothing published from any package, so no changeset — skip-changeset.

Generated by Claude Code


Generated by Claude Code

`discoverFamilies` hands the same source string to six analysers in one pass
of its per-family loop, and each re-derives the masked body from scratch — two
of them twice, since they mask and then hand the masked text to
`anchoredReadTargets`, which masks again. One source pays `maskComments` about
seven times and `maskSelfTests` about five, per discovery, for bytes that
cannot have changed in between.
A V8 CPU profile of one `discoverFamilies()` call (201 families, 196 distinct
gate sources, 11.8 MB) spent 14.3 s, of which `maskSelfTests` was 4.5 s of self
time (31.7%) and the `maskComments` inside those six analysers most of another
5.2 s — the largest entry in the profile, and everything above the first pass
is repetition.
Both maskers are pure functions of their input string, so they are memoised on
it, behind a byte-bounded cache. Nothing about what is masked, scanned or
discovered changes: same bytes in, same bytes out, the same derivation run once
instead of a dozen times. The set of families and the verdict of every
self-test case are held byte-identical.
Measured on this tree: one discovery 13.6 s -> 4.9 s cold, 13.4 s -> 2.6 s on a
repeat within the same process.
@claudeclaudeBot added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 2, 2026
@baozhoutao
baozhoutao marked this pull request as ready for review September 2, 2026 13:52
@baozhoutao
baozhoutao added this pull request to the merge queueSep 2, 2026
Merged via the queue into main with commit 3bca6a4Sep 2, 2026
36 checks passed
@baozhoutao
baozhoutao deleted the claude/issue-14521-dispatch-gates-selftest-profile branch September 2, 2026 14:17
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[finding] check:pm-dispatch-gates repeatedly holds the shared verify lock 500-900s+, starving the queue

2 participants

@baozhoutao@claude