Handoff: Reproduce and fix the JAR-history period-bounds test timeout
Written 2026-10-22 UTC; original review CI snapshot refreshed at 09:43 UTC.
RE-VERIFY: This is a write-time snapshot. Recheck ContainerNursery main, the branches below, and the current PR state before acting. Use gh pr view https://github.com/CodexCoder21Organization/ContainerNursery/pull/702 --json state,headRefOid,mergeStateStatus,statusCheckRollup,mergedAt and git ls-remote for branch heads.
Design decisions in force
The owner's direction for this effort, verbatim, 2026-10-21: "Do we have comprehensive e2e tests? Including scale tests as per https://github.com/CodexCoder21Organization/DocumentationRepository/blob/main/architecture/TESTING.md#extreme-condition-testing-load-fuzzing-failure-injection-and-chaos" / "If there are gaps, have sol write the missing tests." / "Then, do another round, Your goal is to add end-to-end integration tests which identify bugs (the tests should initially fail), and then fix the bug in the implementation."
Lane rules, 2026-10-22: "Absolute rules: never increase a timeout, never reduce an iteration count, never disable/skip/delete a test, never weaken an assertion, no mocks (no mockito), no reflection, never make a private member public for a test. A failing test is a defect report: fix the cause. Error messages state what was wrong and the actual value."
"Build/test: scripts/build.bash --local and scripts/test.bash --local --test <name> --log <file.xml>. Never --remote (killed remote clients leave orphaned runs). The runner retries a failed test up to three times; count a pass only when attempt 1 passed (no attempt-history in the XML)."
"You may not merge, enqueue, publish artifacts, deploy, restart services, or delete/rerequest buildtest runs." Keep these restrictions unless the owner changes them. The existing 30-second test watchdog and 102 iterations remain in force; no JVM tuning flags were added.
Mission summary
This additional defect was observed while addressing the review of https://github.com/CodexCoder21Organization/ContainerNursery/pull/702. That review concerns two direct-RPC regression tests. Its requested focused tests passed 5/5 each on attempt 1, seven separate regression controls failed as intended, and both new tests passed on attempt 1 in the one full local suite. The full run exposed an unrelated timeout in the existing testJarHistoryBoundsPeriodsAcrossRestart, on unchanged main source. This handoff covers that timeout, not a request to merge or deploy the original PR.
The remaining work is to find a reliable reproducer and the specific mechanism, then fix it at the owning layer with a failing-to-passing test and a separate PR. No implementation fix has been made and no root cause has been established. Do not infer a fix from the isolated passes below.
What was found and done
-
The first and only full suite for reviewed head 35f3d168884c7bb51933558fa5c5c87f397da5d3 started at 08:26:41 UTC under the machine-wide lock and ended at 08:50:27. Runner exit was zero with 901/901 final successes, but the XML contains one global attempt-history: history period-bounds attempt 1 timed out after 32485 ms against its unchanged 30000 ms watchdog; attempt 2 passed in 12449 ms. Thus only 900/901 were first-attempt successes. No full suite was retried. XML history is a sibling of test records; search the entire XML tree, not inside each <test>.
-
The failure message was Test 'testJarHistoryBoundsPeriodsAcrossRestart' timed out after 30000ms (no stuck-frame hint could be extracted from the captured console output: consoleTextLength=215153, markersPresent=[Full thread dump, JNI global refs:, [JSTACK THREAD DUMPS BEGIN]], markersAbsent=[no thread dumps, jstack did not complete, jstack binary could not be located, jstack produced no output, kompile in-child self-dump, "main"]). Its full stack reaches Workspace.executeTestInSeparateJvm:4857, executeTestAttemptSafely:4942, prepareTests executeAction submitNext:7079, then FutureTask/ThreadPoolExecutor/Thread.run. The complete error, console, and JVM dumps are preserved remotely; use those files instead of this abbreviated stack.
-
At the captured timeout dump (JVM elapsed about 31.38 seconds), main was absent. DestroyJavaVM had elapsed 0.58s; the only non-daemon worker was Netty globalEventExecutor-2-6, elapsed 0.62s, parked in GlobalEventExecutor.takeTask:118 / TaskRunner.run:283. Application logs showed all 204 activations, restart/legacy normalization assertions and nursery cleanup completed. This proves it was waiting for JVM exit at capture time; it does not identify why earlier application work consumed its budget. Do not call it a deadlock or attribute the whole timeout to the last Netty wait without more evidence.
-
Shared memory is one 10 GiB cgroup. Pre-suite memory.current was 8188588032 bytes; sampled peak was 10737418240. All samples are in the remote evidence file. The suite was not killed, and a later cgroup snapshot showed oom=0/oom_kill=0; that later snapshot alone does not diagnose this timeout. No host-load explanation is established.
-
Fresh shallow ContainerNursery main clone CN702-jarhistory, main head 760f3644d95a8bef2893d06f501531917f58fc9b, was read including AGENTS.md and README.md. Unmodified targeted history test passed on attempt 1 in 15134 ms. Build rule took 187319 ms in the fresh cache. Then a timing-only copy passed on attempt 1 in 12895 ms and 16388 ms; all XMLs had zero attempt-history. There is no reliable failing reproduction yet.
-
The diagnostic copy is tests/testCn702JarHistoryTiming.kts on the diagnostic WIP branch. It preserves all original assertions, counts, request timeouts and watchdog. It adds request and history-persistence fence timing, writing measurements to ../../out/CN702-history-profile.txt. The first revision printed console only, which successful-test XML omits; second revision writes a scratchpad file. Create ../../out before running the probe; use the standard workspace layout or change only that diagnostic output path. Measured run: availableProcessors 16, 412 requests completed before first restart in 9474 ms, POST request time 4963 ms, GET 2738 ms, max request 431 ms. No persistence fence exceeded 50 ms. These are phase measurements, not proof that the timeout is fixed.
-
The original scenario uses real HTTP and native temporary JAR upload/install/read paths, with a serialized in-memory Okio history/log store. It alternates two distinct JAR contents 102 times (204 activations,205 uploads including final fence), verifies 100 retained periods and two discarded per content with exact timestamps, restarts and verifies again, then loads 103 legacy periods and verifies the normalized 100 and discarded count 3, including exact persisted JSON values. It starts/stops the same HTTP facade across three nursery instances. All of this coverage must stay.
-
The full suite also emitted several kompile.TerminalMemoryWarningEffect records: a terminal-memory line was followed by later stdout. The first exact warning and full stack are in the evidence file; the entire log preserves subsequent warnings. No cause is known and no runner patch was made. The challenge CLI would auto-enqueue/merge, contrary to the lane prohibition, so the permitted WIP record was used instead.
Relevant PRs / refs
| Repo |
Branch |
Remote head SHA |
PR |
Contents |
State |
| ContainerNursery |
tests/r1-C2-retry-removal |
35f3d168884c7bb51933558fa5c5c87f397da5d3 |
https://github.com/CodexCoder21Organization/ContainerNursery/pull/702 |
Two reviewed direct-RPC tests |
Open; focused 5/5 each, local full 900/901 first-attempt; both GHA jobs green, reverify |
| ContainerNursery |
wip/cn702-review-checkpoint |
35f3d168884c7bb51933558fa5c5c87f397da5d3 |
same PR source |
Milestone copy of reviewed source |
Same tested source |
| ContainerNursery |
wip/cn702-review-evidence |
9b0a3bcab9bb75d147e5c499187c1b56192c1e8e |
no PR |
Findings, full XML/log/dumps, memory, controls, diagnostic XML/measurements |
Evidence only |
| ContainerNursery |
wip/cn702-history-diagnostic |
5a939aedf2b287569b145665a6b64d16c9149c82 |
no PR |
Timing-only copy of history scenario |
Compiles/passes; no reliable timeout reproducer, no fix |
Essential artifacts under the evidence branch's lane-evidence/: CN702.md, CN702-full.xml, CN702-full.log, CN702-full-started.txt, CN702-full-memory.log, CN702-jarhistory-failure.xml, CN702-history-attempt-1.txt, CN702-history-attempt-2.txt, CN702-history-isolated.xml, CN702-history-timing.xml, CN702-history-timing-2.xml, CN702-history-profile.txt, and corresponding logs. The original review's independent controls are also preserved there.
No production code or artifacts were deployed/published, no service restarted, no PR merged/enqueued, and no CI/buildtest run rerequested during this effort. This is verified from the performed commands and the finalization delegate's bounded observation-only brief. Read-only UrlResolver/UrlProtocol source clones had no changes or stashes. Dependency caches, generated jars and compiler output are deliberately excluded from branches; the source and diagnostic evidence are remote.
Original review CI snapshot at 09:43 UTC: PR remains OPEN with CLEAN merge state and exact tested source 35f3d168. Both bld-build and bld-build-release completed successfully. CI artifact inspection found 901 final successes but 900 first-attempt successes: an unchanged backend-close test failed its handler-completion assertion once, then passed. Both Direct tests passed first attempt. Its separate deterministic cancellation-order control fails 3/3; see the backend-completion handoff. That failure is distinct from this history timeout. No merge or enqueue. This does not resolve the local history timeout.
The additional diagnostic branch wip/cn702-backend-completion-control, remote head 7461f99db31ba13351e3343b4b8c6a038e0c5324, preserves the independent callback cancellation-order control. It built and failed the original backend-completion assertion 3/3; no fix or PR. This is separate from the period-bounds diagnostic and has its own handoff.
Related investigation, not an established common cause
The existing deployment-bounds timeout investigation targets testJarHistoryBoundsDeployments, a different 200-iteration scenario. Its unchanged real-companion sample reached the watchdog 1/4 times and its prior isolated samples passed; its cause is also unresolved. Captures there show different active phases (hash formatting or HTTP shutdown), so do not equate that investigation with this period/restart timeout without new evidence. Its saved public-path scheduling and phase tools may help.
The broader history follow-up handoff records unvalidated cost changes on a separate WIP branch and two bounds tests timing out in a wider register. Read it critically; no candidate from that work was applied here, and its merge/deploy instructions do not override this lane's prohibitions. These are context links, not dependencies that require this investigation to wait.
Next steps
- Reverify live main and PR/branch state first. Clone fresh into workspace, read AGENTS.md/README, and read all of https://github.com/CodexCoder21Organization/DocumentationRepository/blob/main/architecture/TESTING.md and https://github.com/CodexCoder21Organization/DocumentationRepository/blob/main/PHILOSOPHY.md before writing tests. Preserve the constraints above.
- Recover the evidence and inspect the complete failure console and thread lifetimes. Establish the specific phase that exceeded its expected work; distinguish handler/install time, persistence fences, server startup/shutdown, and child-JVM exit. The current evidence does not support selecting any one as the cause.
- Run the unchanged public test path with
scripts/test.bash --local --test testJarHistoryBoundsPeriodsAcrossRestart --log <xml>. The timing copy can help measure phases. These have passed in isolation; they are not a reliable reproduction. Amplify only with genuine callers/operations, never CPU spinners, host tuning or JVM flags. Once a mechanism is named, force that condition deterministically; do not calibrate concurrency to one machine.
- Before any fix, write the mechanism and reliably failing reproducer in findings. If touching lifecycle/ownership/concurrency, build the invariant table and derive tests through public APIs. Do not change the existing 102 iterations, assertions or 30-second watchdog. No speculative timeout/fallback patch.
- Fix at the owning layer, prove the same reproducer flips to passing, review tests and code independently, rebase/build/test, and open a separate PR with the observed full-suite timeout as its WHY. Keep owner-required coauthor/footer conventions. Do not merge or deploy without a changed authorization.
Operational notes
Full suites use flock /tmp/claude-501/complete-suite.lock scripts/test.bash --local --test . --log <xml> and record /sys/fs/cgroup/memory.current before/every few minutes. Never repeat a suite killed for memory. Queue admission and suite-runtime deadlines must be separate so queue wait does not consume execution time. Track long processes with hard deadlines, recognize all terminal outcomes, stop them before reporting finished, and confirm with ps -eo pid,args -ww.
GitHub status polling is at most once per two minutes. Required jobs here are GitHub Actions bld-build and bld-build-release; the all-tests workflow is disabled on main. kotlin.build (remote) is informational. An old no-run kotlin-build-ci-test suite on the checkpoint branch caused watchman alerts, while the PR-specific GHA suites dispatched normally. Never warm/rerequest because of that stale alert. Do not use --to-merged.
The handoff format README still mentions merging handoff PRs; current create-handoff skill explicitly retires that route in favor of handoff-cli at url://handoff/. The lane also prohibits merging. This handoff uses the service only.