Handoff: buildtest CI timing-flakes hardening (PR #314) + root-caused runner test-parallelism gaps

Written 2026-07-14 — RE-VERIFY banner

Every state claim below is a write-time snapshot (2026-07-14 ~08:55 UTC) and must be re-checked before acting. PRs merge, CI re-runs, branches get force-pushed, services restart. Authoritative re-checks:

• PR: gh pr view 314 --repo CodexCoder21Organization/BuildTestEmbedded --json state,mergeStateStatus,statusCheckRollup,headRefOid,mergedAt
• A buildtest run's phases/tests: on the prod host ssh -p 23 root@198.199.106.165, files under /root/buildtest-data/runs/<runId>/ (run.json, test-events.jsonl, test-results.json).
• A fresh query always wins over this document.

Mission summary

Governing user directive (a repeated /loop): "keep going… you must not stop until your PRs are all green and merged. Prefer to debug locally by reproducing production issues in a test (initially failing) then get it green (TDD). Fix underlying infrastructure/flakes as needed… Update the production ContainerNursery env vars for buildtest so it shards across up to 10 droplets with at least 4 tests running in parallel per droplet (ideally 40 parallel; min shard size 25 on >250 tests). In practice I've never seen parallelization anywhere near 40 — investigate why and fix this. Ensure builds aren't stuck 'pending'. Crash recovery should be graceful (STATE_MANAGEMENT.md#crash-recovery) and comprehensively tested in hermetic tests."

The immediate deliverable in flight is PR #314, which hardens the BuildTestEmbedded test suite so it stops flaking under sharded CI. This session it expanded into a 63-file timing-hardening sweep, and then — after the user rejected a droplet-size/CPU hypothesis — pivoted to root-causing why the runner never sustains 4 concurrent tests per droplet.

What was found and done (the chain)

1. PR #314 = branch fix/deterministic-admission-crash-recovery, head 56407c4 (pushed; local == origin; working tree clean). Three commits on top of the prior baseline 03316d6:
   • d89411f "Make concurrent project-name test wait for analysis"
   • b4d576a "Make build-log streaming test signal driven"
   • 56407c4 "Replace timing polls with completion signals" (the broad sweep)
   • Net: 63 test files changed, +1210/−353, ZERO product-source files. The sweep replaces wall-clock waits (Thread.sleep, System.currentTimeMillis()/nanoTime() poll-until-timeout loops) with condition/completion signals (latches, stream-drains, await-predicate helpers).
2. The two originally-named flakes were reproduced and fixed (VERIFIED):
   • concurrentSubmitBuildsDoNotGarbleProjectNames.kts — reproduced 10/10 fail under CPU-pinned amplification, then 0/10 fail after the fix. Finding: NOT a product bug — the test's fake createDroplet threw instantly, so under load a build reached FAILED before its background project-name analysis populated names. Fix defers the fake's provisioning failure (via a releaseProvisioningFailures latch) until after names are captured, while keeping all 12 analyses concurrent. (Product diff was only 2 cosmetic blank-line removals, later reverted.)
   • e2eStreamBuildLogDuringExecution.kts — 30s @Timeout overrun fixed with condition-waits.
3. Adversarial + comprehensiveness review (codex gpt-5.6-sol/high) of the full 63-file diff returned CHANGES-REQUIRED for ONE minor residual only: three WatchService replacements retain a 2-second wall-clock deadline (orphanedBuildEnqueuesDeletionInsteadOfInlineDestroy.kts:116 and 2 others). It explicitly confirmed: no weakened/removed/broadened assertions, no disabled tests/hidden skips, both named fixes legitimate (all 12 analyses overlap; streaming test still asserts non-empty phase output on a non-terminal run), compilation clean across all 63 files. So the sweep has integrity.
4. CI still fails ~2 DIFFERENT timing tests per full 531-test run (529 PASSED / 2 FAILED each time):
   • run cd47d6a8: concurrentSubmitBuildsDoNotGarbleProjectNames + e2eStreamBuildLogDuringExecution (the pre-sweep pair).
   • run 35810bfd (post-sweep, head 56407c4): e2eListBuildRunsDuringActiveBuild (build took 23.7s to reach its started latch vs a 15s bound) + e2eXmlResultsShouldNotOverwriteBtrErrorMessages (36s vs a 30s @Timeout).
5. Droplet-size/CPU hypothesis — RAISED then REJECTED by the user. I initially proposed the flakes were CPU starvation (CI droplets are s-2vcpu-4gb, DropletManager.kt:118 DEFAULT_SIZE, running up to 4 heavy e2e JVMs). The user rejected this: "Each test runs in a separate process, parallelism is entirely independent of the number of CPU cores… more cores means each test finishes faster and thus LESS overlap… the problem is never droplet size." Do not pursue droplet size.
6. VERIFIED root cause of the under-parallelism (the user's actual question). Phase timing of run 35810bfd (from its run.json phaseTimestamps):
   • PROVISIONING→INSTALLING 48s · INSTALLING→UPLOADING 184s · UPLOADING→BUILDING 0s · BUILDING→TESTING 10s · TESTING→COLLECTING 1221s · total 1467s.
   • Each of the 10 shards is well balanced (52–59 tests) with only ~464s of summed test-time each. At true 4-way parallelism a shard's tests finish in ~116s, yet the TESTING phase ran 1221s — i.e. tests execute with large gaps between dispatches; nowhere near 4 concurrent. Measured global peak concurrency = 24, not 40, and sustained average is far lower.
   • Conclusion (verified by timing, consistent with the user's framing): this is a runner test-dispatch SCHEDULING problem — the on-droplet runner is not keeping ~4 tests running concurrently; there are big gaps. It is NOT CPU/droplet-size. This is simultaneously the cause of "never near 40" AND likely of the timeout flakes (a test that waits a long time in a dispatch gap, or whose setup is delayed, blows its bound).
7. Production is healthy (verified this session): buildtest service uptime steady, homepage HTTP 200, no stuck-PENDING runs; the 0.0.276 admission-wedge fix is holding.

Relevant PRs / refs (write-time state)

| Ref | State @ write time | Link | |---|---|---| | PR #314 (the sweep) | OPEN, mergeStateStatus BLOCKED, kotlin.build (remote) = FAILURE on head 56407c4 | https://github.com/CodexCoder21Organization/BuildTestEmbedded/pull/314 | | Branch | fix/deterministic-admission-crash-recovery @ 56407c4 (pushed, tree clean) | — | | Failing run (post-sweep) | 35810bfd — 529 PASSED / 2 FAILED | https://buildtest.kotlin.build/run?id=35810bfd | | Earlier failing run | cd47d6a8 — 529 PASSED / 2 FAILED | https://buildtest.kotlin.build/run?id=cd47d6a8 |

Local checkout: /code/BuildTestEmbedded-task19 (on the branch). CI droplets: s-2vcpu-4gb, region sfo3. Prod buildtest env vars currently set: BUILDTEST_MAX_TEST_SHARDS=10, BUILDTEST_DROPLET_LIMIT=75 (no per-shard-parallelism or droplet-size var exists).

Next steps (ordered — re-verify current state FIRST)

0. Re-verify #314 state and re-pull run 35810bfd phase timing before acting (commands in the banner).
1. Investigate the buildtest-runner's on-droplet test-dispatch scheduling — the core task. Find why it doesn't keep ~4 tests concurrently running per droplet (the 1221s-vs-464s gap). Likely suspects: batching (waits for a whole wave of 4 to finish before starting the next → stragglers idle the other slots), serial per-test setup/teardown, or a discovery/serialization phase. You will need the buildtest-runner source (the artifact the droplets run; version pinned via BUILDTEST_RUNNER_VERSION in BuildTestEmbedded src/buildtest/embedded/BuildDriver.kt). Clone it fresh; do not assume it's checked out. The parallelism knob ("4 tests per droplet") is implemented there or in how it invokes the kompile test runner — it is NOT a BuildTestEmbedded env var.
2. Reproduce the gap locally / measure achieved parallelism as a fail-first signal (e.g. instrument or compute max-concurrent from test-events.jsonl; note events currently carry only event,name,project,timeoutMs,timestamp — no shard tag, so per-shard concurrency must be reconstructed from the per-shard runner-spool-offset-sN.txt or the on-droplet logs).
3. Fix the under-parallelization at the runner layer so a droplet sustains ~4 concurrent tests (continuous dispatch pool, not fixed batches). This should also shrink the TESTING phase dramatically and likely remove the flakes (fewer/shorter dispatch gaps). Follow TDD; do NOT raise any timeout; do NOT touch droplet size.
4. Apply the review's residual finding: the 3 WatchService 2-second wall-clock deadlines (orphanedBuildEnqueuesDeletionInsteadOfInlineDestroy.kts:116 + 2 others) — make them condition-driven.
5. Re-run #314 CI only after the scheduling fix (don't gamble on re-runs: with ~2/531 flaking, P(all-green) was ~12%).
6. Merge #314 (pre-authorized for this effort) once kotlin.build (remote) is green: enqueue via the merge queue (repo uses GraphQL enqueuePullRequest; gh pr merge --auto is disabled), never --delete-branch.
7. Parked: republish BuildTestEmbedded + rebuild/redeploy buildtest-server-service after merge to keep prod matching main (0.0.276 is deployed now).

Reusable / operational knowledge

• Delegate the build/test/fix to codex gpt-5.6-sol per global CLAUDE.md: codex exec --dangerously-bypass-approvals-and-sandbox --model gpt-5.6-sol -c model_reasoning_effort=high -C <repo> "<brief>" < /dev/null — always append < /dev/null (stdin hang) and -C <repo> (cwd leak). Run backgrounded and monitor its output file.
• Measure a run's real parallelism from test-events.jsonl: count test_started(+1)/test_completed(−1) over sorted timestamps for max concurrency. Phase split is in run.json phaseTimestamps (added earlier this workstream).
• The "flake" is a genuine defect, not environmental — but the owning layer here is the runner's scheduler, per the user: parallelism is a scheduling property independent of CPU cores; "the problem is never droplet size."
• Adversarial/comprehensiveness review before trusting a large mechanical sweep — a 63-file test change can hide a weakened assertion that green CI won't catch; a fresh codex review caught only the WatchService residual and cleared the rest.
• watch CI with build-watchman (coursier launch buildwatchman:build-watchman:0.0.12 -r https://kotlin.directory -- --repo <o>/<r> --pr <n>), not a hand-rolled poll loop; it exits on terminal (its exit is an actionable event, not "still watching"). Add --to-merged only when you intend it to enqueue+merge on green (do NOT use --to-merged while a human review gate is still pending).
• Server access order: ContainerNursery CLI > HardwareControlFabric > SSH (ssh -p 23 root@198.199.106.165). Runs live at /root/buildtest-data/runs/<id>/.
• Related standing tasks (not this PR): SJVM host-side RPC interrupt / metaspace leak (UrlResolver SandboxedConnection.close() should call sjvm.close()); runner-durability on SSH disconnect.