Activity

1. MendixMau commented on Oct 16, 2026

   

   MendixMau

   on Oct 16, 2026

   OwnerAuthor

   More actions

   Study: why Stage 5 was slow, and what the speed-ups did

   Scope: a field migration project (Next.js + PostgreSQL to Mendix 11.15, 12 modules), Stage 5 development, 2026-10-16 to 2026-10-17. Read-only study: no exec, no mxbuild, no .mpr or private-copy access.

   Convention: M = measured, with source. E = estimated, with method. Nothing here is a guess without a method. Where an instrument did not record a quantity, the table says "not measured".

   Sources used (short names):

   • ledger: the per-exec metrics ledger, 113 rows, one per exec attempt, with elapsed_s and result.
   • time ledger: the self-reported phase table kept by the lead.
   • transcripts: the lead session transcript and every subagents/agent-*.jsonl. True token spend is the sum of assistant usage fields (fresh = input + cache write + output; cache read reported separately).
   • deep dives: three written failure analyses (mxbuild failures, process environment, blocked and unverified runs) and the project-agent research note.
   • staging: per-phase MANIFEST and NOTES files from the parallel authors.
   • look files: look ledger (owed and seen), UI review reports, page fidelity table, improvement register.

   Caveat that applies to every token figure: the subagent_tokens value in task notifications is a context-size snapshot, not spend. The time ledger's token column uses it, so it understates spend by an order of magnitude (see Q2).

   Headline findings

   1. The mxbuild gate was only 27% of the ledger window (99.9 of 376 min, M). The other 73% (276 min, M as the sum of gaps between exec rows) is authoring, look loops, waiting and failure recovery, and the ledger cannot separate those. Making the gate faster alone cannot give more than about a quarter.
   2. A third of exec attempts did no useful work: 27 of 113 rows (24%) were gate-not-run, gate-failed or rolled-back, costing 26.3 min (M). 17 of the 27 trace to one cause, the live run --local --watch racing the gate's mxbuild on deployment/ (deep dive). That is a toolkit defect, not an operator mistake.
   3. Parallel authoring cut wall clock for phases 4 to 6 from a self-reported 335 agent minutes to about 33 min wall (time ledger, M), but it spent more tokens, and wave 2 authors each re-replayed the P4 to P6 base. It worked on time and partly on tokens. It cost quality signal in one place: proofs on private copies were stopped early and cannot be re-verified from the copies.

   Q1. Where the wall clock went

   Exec/gate (M, ledger)

   Result	Rows	Minutes	Share of exec min
   applied-lint-rose (clean apply, lint exit 1)	58	56.6	56.7%
   gate-not-run	19	20.3	20.3%
   applied-unverified (mxbuild exit 3, write kept)	10	11.9	11.9%
   gate-failed (CE code, rolled back)	7	5.0	5.0%
   partial	2	2.6	2.6%
   applied	1	2.1	2.1%
   rolled-back	1	1.0	1.0%
   blocked (pre-exec guard)	15	0.4	0.4%
   Total	113	99.9	100%

   Ledger window: 10:16Z to 16:33Z on 2026-10-16, 376 min (M). Exec = 99.9 min (26.6%). Time between exec rows not inside an exec = 276 min (73.4%, M as sum of gaps).

   Split of the whole window (mixed evidence)

   Bucket	Minutes	% of 376	Evidence
   Exec useful (applied, applied-lint-rose, applied-unverified, partial)	73.2	19.5%	M, ledger
   Exec failure recovery (gate-not-run, gate-failed, rolled-back, blocked)	26.7	7.1%	M, ledger
   Of which reruns of already applied scripts	about 18	about 4.8%	M, deep dive count (19 reruns, 10 in the Phase 1 full rerun)
   Authoring, drafting, look loops, waiting, idle (inseparable)	276	73.4%	M total, split not measured

   The inseparable 276 min cannot be honestly split by the ledger. Partial evidence only:

   • The time ledger credits Phase 2 (100 min) and Phase 3 (92 min) with "look loop" time. The transcripts show that part of this was the S5-17 bisection and journey test authoring, not looking. The label is wrong, the split is not measured.
   • Agent tool time from tool_use to tool_result timestamps captures foreground calls only. It shows Phase 1 exec as 3.9 min against 25.4 min in the ledger, so it under-counts background exec by a factor of about 6. Not used for exec.

   Three eras (M, time ledger plus ledger)

   Era	Wall clock	Mode
   Phases 0 to 3, sequential	54 + 55 + 100 + 92 = 301 min	one agent per phase, serial
   Phases 4 to 6, parallel authoring	about 33 min to last finish	three authors on private copies
   Replay of 4 to 6, then phases 7 to 9	still running at about 00:27 on 10-17	final totals not available

   Q2. Where the tokens went

   Method: summed assistant usage per agent file. Fresh = input + cache write + output. Cache read shown as the second figure. All M (transcripts). P7, P8 and replay were still running at the time of counting, so their rows are partial lower bounds.

   Task type	Fresh tokens	% fresh	Cache read	% cache read
   Sequential phase agents P0 to P3	1,968,725	26.2%	90,811,941	39.6%
   Parallel authors P4 to P9	2,127,085	28.3%	83,855,500	36.5%
   Executor replay (partial)	417,983	5.6%	4,333,679	1.9%
   Deep dives and research (4 agents)	692,198	9.2%	23,646,708	10.3%
   Meta agents (board, skill gaps, field test, bug filing, PRs)	433,254	5.8%	7,119,708	3.1%
   Lead orchestration	1,888,221	25.1%	19,835,239	8.6%
   Total	7,527,466	100%	229,602,775	100%

   Per agent (fresh): P0 345,574; P1 326,249; P2 541,733; P3 755,169; P4 289,005; P5 221,285; P6 276,109; P7 530,097; P8 477,017; P9 333,572.

   Look review tokens are not separable: look loops ran inside the phase and author agents, not as their own agents. Not measured.

   Tokens per applied script (E): 7,527,466 fresh / 69 applied ledger rows = about 109k fresh per applied row. Method caveat: 69 counts applied, applied-lint-rose, applied-unverified and partial rows including reruns, and the total includes diagnosis, meta and orchestration work that no script needed. Treat as an upper bound on the building cost and a fair measure of the whole programme cost.

   Comparison against the time ledger (M, both sources): the time ledger lists 175k, 136k, 189k and 100k for P0 to P3 (600k in total) against 1.97M fresh measured, so self-reported figures were low by a factor of about 3.3 on fresh and miss cache read entirely.

   Q3. The speed-ups, with verdicts

   #	Speed-up	Before	After	Verdict	Side effects
   1	Parallel authoring on private copies, single executor replay	Phases 4 to 6 self-reported 335 agent min; sequential pace of phases 0 to 3 was 54 to 100 min per phase (M)	about 33 min wall to last finish (M)	Worked on time, partly on tokens	Duplicate base replays and compiles in wave 2 authors; extra tokens (parallel authors 2.13M fresh, 28% of total); CPU contention; merge scripts needed (47, 48, 79z, 99); early-stopped proofs
   2	Look loop capped at 2 rounds	Phase 2 took 100 min with look loops (M, mislabelled in part)	Not isolated: no per-round timing in any instrument	Not provable	30 look rows owed against 1 seen (M, look files): the cap, plus a hook that did not record looks, left most pages without a recorded look
   3	No full reruns	Phase 1 full rerun, 10 reruns, about 15 min waste (M)	19 reruns of applied scripts in the whole ledger window, about 18 min (M, deep dive)	Partly: no repeat of a Phase 1 style full rerun, but reruns still occurred, so the time ledger's "no full reruns" claim was wrong as stated	None
   4	Generator tools/stage5/gen_domain.py (376 lines, generating domain scripts 06 to 15)	Hand-written domain scripts in the early phases	Generated scripts reached exec with no measured authoring minutes	No before/after measurement; plausible win, not proven	Generated scripts inherit one defect to all outputs (a single SKU fix was needed late)
   5	Pause the watcher during exec	17 of 27 failed gates came from the watcher race (M, deep dive)	Instruction issued 16:18Z to 16:27Z; ledger ends 16:33Z, so about 6 to 15 min of data, too few rows to compare	No data yet	Operator practice only: exec.sh has no pause, lock or gate mode
   6	General-purpose agents adopting role files instead of project subagents	Intended: project role agents	Project agents are discovered by walking up from the launch cwd, the lead launched in the wrong workspace, so none loaded (M, research note)	Did not work as designed; the workaround functioned but is not comparable	Each agent re-reads role files into its context; not separately measurable

   Side effects, with numbers

   Side effect	Evidence	Number
   CPU contention	process environment deep dive	load 68 on 14 cores, an apply 68% slower (M, deep dive)
   Duplicate compiles	each private copy runs its own mxbuild, then the replay runs it again on the real model	not counted per phase; E: at least 3 compiles per script across 3 parallel authors plus replay
   Duplicate base replay by wave 2	P7 to P9 authors replayed the P4 to P6 base	author fresh tokens P7 to P9 = 1,340,686 (M), the duplicate share is not separable
   Navigation and startup merge work	merge scripts 47, 48, 79z, 99, plus P9 starting from a partial base	script count M (4), minutes not measured
   More tokens	parallel authors 2,127,085 fresh vs the sequential agents' pace	no like for like baseline; E: parallel total is about equal to phases 0 to 3 for 6 phases against 4
   Early-stopped proofs	authors stopped proofs on copies without git and used FORCE_EXEC=1	proofs on copies are not the real model; see Q4

   Q4. Quality signals

   Signal	Reading	Real or instrument failure
   UNVERIFIED rows (mxbuild exit 3, write kept)	10 rows, 11.9 min	Real in the sense that the build did not finish, but every one was later covered by a clean whole-model build (E: inferred from later applied rows, not checked row by row)
   verify-module Administration	INCOMPLETE: 28 pass, 1 fail (unknown), 40 not run; conformance 0 rows in 2 ledgers; coverage timed out at 300 s; journey json missing; monkey and design audit faulted	Instrument failure: conformance needs backticked SHOW or DESCRIBE, journeys need a different file shape, coverage budget is below the model's need. Not evidence of a defect in the model
   Lint	LINT ROSE exit 1 on 57 of 58 clean runs against a frozen 9 finding baseline	Instrument failure: exit code is not a pass or fail signal
   Look defects	30 look rows owed, 1 seen (M); defects deferred to the improvement register	Mixed: the hook (look-ledger.sh) records owed on write and seen on screenshot, but looks happened without being recorded. The true count of unlooked pages is not measured
   Page fidelity scores	PAGE-FIDELITY table exists per page	Real, but covers only pages that were built and shot
   Early-stopped proofs on copies	replay agent re-proves on the real model	Real risk. Whether the 7 unapplied replay scripts landed cleanly was not known at count time

   Did any speed-up lower quality? Evidence says: the 2 round look cap and the unrecorded looks probably left cosmetic defects (E: improvement register entries, not re-counted here). Parallel authoring risked correctness on shared objects and was held by the single replay. No measured functional regression is attributable to a speed-up. That statement is limited by the instruments above, which mostly could not measure.

   Q5. What did not speed us up but should have

   Item	Why it did not	Evidence
   Per-script full mxbuild	exec.sh runs mxbuild --target=deploy every script, no batch mode, no gate-skip mode	99.9 exec min over 113 rows, 1 to 3 min each
   Frozen lint baseline	exit 1 on clean runs; every run needs human reading of the output	58 rows
   Watcher race	run --local --watch live during gate	17 of 27 failed gates
   Instruments not trusted	verify-module and conformance incomplete, so verification is deferred debt	summary above
   Project agents not loaded	wrong launch cwd	research note
   Tokens: cache-heavy contexts	each long-lived agent re-reads context on every turn	cache read 229.6M against 7.5M fresh, a ratio of about 30 to 1 (M)

   Ranked top 5 changes for the next run

   Savings are E. Method is stated for each.

   Rank	Change	Type	Expected minutes saved	Expected tokens saved	Method
   1	Batch gate: one mxbuild per N scripts (or per phase) with a per-script static check, rollback by batch	Toolkit	45 to 58 min per run	small (fewer retry turns)	Applied exec time 73.2 min; if one build per 5 scripts, 80% of build time removed, and the 56.6 min of clean applies is the bulk
   2	Make exec own the watcher: pause or lock it for the duration of the gate, and write the build to its own output directory	Toolkit (operator practice until then)	about 16.6 min	about 17 of 27 failed retries of diagnosis turns, not quantified	17/27 of 26.3 min of failed-gate time; excludes follow on reruns
   3	Wave 2 authors start from the replayed base, not a fresh re-replay; launch with project agents from the project cwd	Operator practice	not measured (the duplicate replay minutes were not logged)	upper bound 1.34M fresh (P7 to P9 authors), real share unknown	Bounded only; log the replay minutes next run to settle it
   4	Fix the instruments before the build: conformance ledger shape, journey json per module, coverage budget, lint baseline refresh, look hook recording	Toolkit	removes the deferred verification block; not measured	not measured	Verification debt list; a lint baseline that fails 57 of 58 clean runs costs a read per run
   5	Record per-phase timing in the ledger (author, look, wait) and true tokens per agent, replacing self-report	Toolkit	0 directly; makes ranks 1 to 4 measurable	none	The 276 min unsplit bucket is the largest number in this study

   Limits of this study

   • The inseparable 276 min bucket is the largest finding and the one least understood.
   • Look loop cost, per-round look timing and Phase 3 app restart counts were not recorded.
   • Final totals for P7, P8 and the replay were not in at count time. Token rows for them are lower bounds.
   • Savings in Q5 are modelled from ledger rows, not tested.
2. MendixMau

   changed the title [-][field 2026-10-17] Project subagents never load when the lead session starts outside the project root[/-] [+][field 2026-10-17] Field report: parallel authoring run with private app copies[/+] on Oct 16, 2026
3. MendixMau commented on Oct 20, 2026

   

   MendixMau

   on Oct 20, 2026

   OwnerAuthor

   More actions

   Closing as obsolete: this field report is design input, and each follow-up now has a home. The watcher race behind 17 of 27 failed gates is fixed by pausing the watcher during the gate (dc840ee, #451, released in v2026.10.19, pinned by tests/wave2/test-exec-gate-retry.sh case D). The shared-objects rule shipped as "draft the ready set in parallel, apply serially" in skills/iterative-build-loop.md: rows that write the same document are never in one ready set (d16f578, #343, v2026.10.19). The check-only gate, batch mode and machine-wide mxbuild lock are still open in #444 (iterative-build-loop.md still says exec.sh has no batched-gate mode, and the exec lock is per project). The one follow-up with no other home, reporting agent minutes and wall clock per phase separately (the metrics ledger has neither column today), moves to #444 as its measurement prerequisite.

   ---

   Generated by Claude Code
4. MendixMau

   closed this as not plannedon Oct 20, 2026