Handoff: Measure UrlProtocol full-suite phases and finish a deterministic test-time improvement

Written 2026-10-22 14:40 UTC. SLOW817 investigation started 11:48 UTC. This is a bounded investigation result with unresolved runtime cause and no validated optimization.

RE-VERIFY: All state is a write-time snapshot. Re-read the PR through gh api repos/CodexCoder21Organization/UrlProtocol/pulls/817, compare remote branch SHAs using git ls-remote, and check the machine-wide suite lock plus memory accounting before running anything. A fresh query wins.

Design decisions in force — 2026-10-22

Owner direction, 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 direction, verbatim: "Never raise the limit, never cut iterations, never skip tests: the job must be made to finish well within 90 minutes by finding what is slow." / "Do (investigation first; read-only on PR branches; push only to wip/SLOW817-*):" / "Do not change the CI workflow's timeout."

Operational restrictions, verbatim: "You may not merge, enqueue, publish artifacts, deploy, restart services, or delete/rerequest buildtest runs." / "GitHub API calls are rate-limited across many lanes: poll at most every 2 minutes." / "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)." / "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." / "Do not add JVM tuning flags."

Full suites must hold /tmp/claude-501/complete-suite.lock; record memory.current before and every few minutes. If killed, report memory and stop rather than looping. Commits end with Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>. PR bodies open with the owner's WHY and end with 🤖 Generated with [Claude Code](https://claude.com/claude-code). Update PR bodies through PATCH JSON and read back. Required checks are repository-defined GitHub Actions; kotlin.build(remote) is informational, read its failed log once and do not rerun it. Watch at most 90 minutes. Keep every command tracked with a hard deadline, clean owned processes before final, and never stop another lane.

Mission

Investigate two 90-minute merge-queue cancellations of the original test PR, compare recent jobs/attempt histories, identify expensive tests and growth, and implement the safest clearly test-only optimization only after before/after proof. That original PR merged externally at 12:54:02 UTC; this lane did not merge or enqueue it. Duration reliability remains the question.

What was found and done

1. Historical collection is complete: 18 substantive recent exact job records, 15 available cohort XMLs, 3 older-main XMLs. Three cancelled jobs have no XML. The job matrix, per-attempt CSV, raw ZIPs and offline scripts are on the evidence branch. An independent raw-XML/schema/count audit passed. Existing PR branches were read-only. No CI run was rerun/deleted/requested.
2. The same commit, same 3127 tests, same Ubuntu 24.04.5 image and Temurin container took 57.03min on main and 83.78min in queue. Median first-attempt ratio 1.3992. Normally <5s tests rise 5107.7→7506.3 cumulative child-seconds. Long-clock tests stay near fixed duration. Both apt 6s and private Maven fast. Therefore broad execution/preparation variation exists independently of source changes or slow setup. CPU/I/O/GC/throttle data are absent; the underlying cause is UNKNOWN. Do not substitute an unsupported "hardware slow" claim or raise limits.
3. A separate verified removable setup cost: workflow always updates apt indexes before installing already-present curl. Main57 fetch 6s versus queue66 fetch 8m2s; 476s explains 79% of their 603s Run Tests gap. Both installed zero packages. It is not sufficient for the original cancellations (apt 2s/68s). No workflow edit was made; validate actual tool-present/tool-missing container paths before a separate CI setup PR. This host has no Docker/Podman/strace.
4. Early target/unrelated cancelled jobs show private Maven request maxima 290.6/284.9s versus central <0.2s, about 10 minutes initial dependencies versus 7 seconds in main57. Server-side reason is unknown. Successful 83min same-revision run has fast artifact downloads, proving independent contributors.
5. Main profiles Oct19/20/21/22 contain 2577/2682/2908/3127 tests. Shared 2570 tests slightly faster in aggregate;557 new tests add 1875.8 cumulative child-seconds. Largest fixed-snapshot added-test costs: forwarded streaming 644.667s / 59 tests, callback threading 219.984s / 62, flood 150.053s / 1, freshness 143.932s / 108. These are parallel sums including JVM launch/cleanup, not job-wall deltas. Daily successful workflow medians rise49.8→59.2→64.3→76.8min, with differing small sample sizes and setup/race outcomes.
6. Flood churn actually 149–315s; intentional churn-drop soak 169–174s (150s load + 12s settle); 3000-round worker-reuse 129–138s (already 130s Oct 19); stale reconnect 80–82s; listener idle 68–71s. Forty-one attempts across four names exceed120s. Intentional soak durations and all counts remain intact. Plans for each expensive test and every retry failure are in test-fix-plans.md. Large-answer test workload changed32calls→260calls, so its timing growth is not like-for-like.
7. Correct retry parsing uses root-sibling attempt-history, not children of test. Early provisional zero-retry claims are prominently corrected.18profiles contain 13 histories; 2 tests reach attempt 3 and still fail, others pass 2;10profiles are first-clean. Largest recorded extra attempt cost 92.398child-seconds. Both exact-revision57/84 runs have 1 retry. Cancelled retries UNKNOWN. Full original messages/stacks are in retry-details.md and raw XML; some contain large JSON, so do not dump whole files into chat.
8. Exact workflow/test-script blob comparison matches all 18 cohort revisions. Pinned CLI 0.0.124 uses manager 0.0.207 with four isolated child JVMs and ignores TestWorkerSlots. Later manager scheduling documentation was inapplicable; slot serialization hypothesis REFUTED. CLI exact source suppresses live test/attempt identity and preparation phases, and copies winner XML only on completion. That explains the missing cancellation diagnostics, not the underlying speed difference. Fast57/60 jobs were LOCAL winners after remote infrastructure failures, refuting remote-failure-alone as the cause. No blind toolchain bump is justified.
9. Conditional test-only change replaces real-clock waits in testStaleReconnectCannotRestoreFailuresAfterCandidateCommit with injected ManualClock. Real hosts, held stale dial, ACK/close, registration frames, all timeouts and workload remain. Advances genuine reconnect callbacks 5 + 10 + 20 + 37 = 72 virtual seconds and leaves healthy +75 pending. Public-schedule observations ensure actual asynchronous work completes before advancing. Original unchanged baseline at current main passed attempt 1 in 80.404s, no history, build rule 158.977s. The candidate was never run and is held from a PR: the remote channelInactive latch plus 250 ms does not prove the superseded reconnect worker recorded its result. New retry schedules witness only new workers. An old worker can be paused after leaving the registration monitor while new retries finish, then resume only after service close prevents result recording. This gives a counterexample where the optimized test passes the intended mutant. No public old-result completion witness was found; do not treat three mutant failures on one host as resolving this. See the independent review. Source snapshot is preserved only for recovery; do not open the PR draft.

Relevant PRs / refs

Evidence branch: https://github.com/CodexCoder21Organization/UrlProtocol/tree/wip/SLOW817-evidence

The only existing related PR is the original test PR, externally merged. This lane published/deployed/restarted nothing; command record and diffs contain no such action. No code was put into a service or artifact repository.

Next steps

1. Re-verify current state first, including both branches/PRs and exact main; do not trust this snapshot. Clone fresh into the requested scratchpad workspace. Read README/instructions and the whole testing guide and philosophy.
2. Recover every artifact from the evidence branch's lane-evidence/SLOW817. Regenerate with analyze-growth.py, analyze-bootstrap.py, analyze-artifacts.py, summarize-jobs.py, attribute-test-cost.py, render-report.py; run audit-evidence.py. No network needed. attribute-test-cost may need repository path adjustment when outside a checkout.
3. Resolve the experimental stale-reconnect test completion-order counterexample before running or adopting that change. A public deterministic old-worker completion signal is required; private inspection/reflection/API expansion only for testing is forbidden. If no signal exists, use the next listener-read test plan instead. Do not blindly execute the preserved validation script or DO-NOT-OPEN-pr-draft.md as a safe optimization. The preserved historical plan was: Mutation only removes the stale-generation rejection in private recordSameRelayFailure; NEVER commit the production mutation. Restore exact SHA and empty production diff. Normal tests require attempt 1/no histories; deterministic mutant requires all 3 fail with selector assertion. Keep full XML/logs. Do not repeat unchanged baseline 80.404s unless source changed materially.
4. Prefer the concrete next plan for testRelayListenerPreservesFrameAcrossIdleBoundary: retain real hosts and application SystemClock, inject the public listenerReadClock, observe the actual idle deadline, advance 50 virtual seconds, send prefix/half-body, observe frame deadline at +110 seconds and exact parse reservation, advance 15 seconds across old idle boundary, then send tail and require exact deliveredRequest plus all original budget/registration assertions. A temporary old single-deadline readMessage overload should fail this contract. No patch or baseline exists for this alternative. If a deterministic target proof passes, rebase on latest main, run full local suite under machine-wide lock with memory records, independently review tests/code, commit/push test-only milestone, create separate PR with measured before/after and motivation. Do not include lane-evidence in code branch. Required GitHub jobs must be green; remote check informational. Stop at90min watch cap. No merge/enqueue/deploy/publish.
5. Remaining diagnosis needs bounded durable test/attempt/stage progress plus CPU/I/O/GC measurements at fixed exact revision. It belongs upstream where effects are currently suppressed; no implementation/publishing was attempted here. Historical cancellations cannot reveal the missing active-process identity retroactively. Preserve process isolation and all work; do not combine test scenarios just to reduce startup costs.

Reusable operational knowledge

Original scratchpad is /tmp/claude-501/-code/2abf611d-5e04-4919-84a8-d7b72869d40c/scratchpad. Local checkouts may vanish; remote branches are authoritative. Findings path is out/SLOW817.md, code worktree workspace/SLOW817-clock-reconnect, evidence checkout workspace/SLOW817, other clones are read-only docs/toolchain. Total 10GiB memory includes reclaimable file/slab: inspect memory.stat, not total alone. This lane initially waited overly conservatively on total; refined targeted admission uses anon <=4GiB with abundant reclaimable cache under the free lock. Never infer safe overlap from one earlier low sample.

Exact CLI source: https://github.com/CodexCoder21Organization/kompile-cli/commit/32cbe1ba707b515c7711ec3a6eb5dc960a774a4d Exact manager source: https://github.com/CodexCoder21Organization/kompile-core/commit/40680b32ed8dce4841ee801479da3230e0632d8c Later slot implementation (not pinned): https://github.com/CodexCoder21Organization/kompile-core/commit/8db9c730c7576144689035560451f704a5aefcd7

Central handoff-cli is authoritative. The older canonical git-format document still mentions automatically merging handoff PRs; that is stale against the current skill and this lane no-merge rule. No handoff PR should be opened. report-challenge auto-merges central records, conflicting with this lane restriction, so friction is preserved in findings instead.

Final runtime state

The original baseline is the only local test:80.404s, success=true, zero attempt histories, runnerexit0 at sourcec1f99d15c4bc03dc4299549011b251b089081067. Candidate/mutation/restored/neighbors/full suite never ran. No optimized speedup, full-suite pass or CI result is claimed. No new PR exists (paced branch PR query 14:24 UTC); original PR merged (paced query 14:22 UTC). Both WIP pushes verified by git ls-remote at 14:37 UTC. All five own checkouts have no changes/stashes/local-only commits. Generated jars/caches are deliberately excluded; exact upstream source is recoverable by linked commits. Derived large timing JSON can be regenerated from raw ZIPs rather than stored twice.

Other lanes held/queued the full-suite lock throughout candidate waits; BUMP38 released14:19:43, FIXOOM49972 acquired it, BUG8c26295 queued before our waiter. No other lane was signalled. Root correctness review ended the candidate experiment before execution. Own waiting group27309/27313/27317 stopped and confirmed absent; worker completed. ps -eo pid,args -ww plus exact cwd/argument audit at 14:42:22 found zero owned background processes. Service report uploaded as BLOCKED and own claim released; a final audit follows the last bounded CLI update/readback before response. Full ps includes unrelated command lines and is intentionally local-only; owned-process-audit.json contains the relevant clean result. Handoff health returnedOK at14:37 with a recorded Netty closed-channel warning; full log is retained.

The root investigation cannot name the exact broad same-revision speed mechanism from published data: no CPU/I/O/GC/throttle samples or cancelled-job active test identities exist. This is an explicit evidence limit, not a complete root-cause fix. The report/per-test plans are delivered; further progress requires new bounded measurements and a deterministic test choice, under the existing no-rerun/no-publication restrictions unless the owner changes them.