Handoff: resolve the buckets cold-request bytecode wait

Written 2026-10-20, approximately 02:17 UTC.

RE-VERIFY: This is a write-time snapshot. Re-check CLI routes/health/container logs, live HTTP checks, and https://github.com/CodexCoder21Organization/SearchableBucketServiceServer/pull/23 before acting. Handoff state is maintained through handoff-cli. The latest forensic evidence is linked below.

Design decisions in force

Original owner requirement, carried forward on 2026-10-20:

startup (and incremental recovery) should always be fast. If there is any situation where startup or incremental recovery are slow, that's a bug which should have been tested and exercised by https://github.com/CodexCoder21Organization/DocumentationRepository/blob/main/architecture/TESTING.md#extreme-condition-testing-load-fuzzing-failure-injection-and-chaos and which should be fixed.

The r22 brief explicitly authorized one target-only CLI 0.0.20 restart and read-only SSH because this machine lacks HardwareControlFabric certificates. That one restart has now been used. Its other rules were:

No other production changes: do not touch other routes, ContainerNursery itself, timeouts or budgets. No code changes or PRs. Waits have hard deadlines. Stop every process you started.

Reproduce it with read-only means if possible (do NOT restart the buckets WUI or ContainerNursery).

If it is a defect, name the owning repo, file and line, and propose the test (a deterministic, failing-first reproducer) and the fix. Do not fix it in this brief.

The earlier deploy's old stop condition was superseded by r22's explicit authorization to resume. No broader production change or code fix has been authorized.

Mission

Original user request: “We need to investigate why https://my.externalbrain.wasmserver.com/ is failing to load and fix the underlying problem.” Server 0.0.17 was deployed from reviewed but unmerged source. r22 was asked to finish its restart/API/search/browser verification and investigate the first buckets 503, without changing code.

What is verified

• The route remains /root/ContainerNursery-uploads/jars/searchable-bucket-service-server-0.0.17-f2efa08-20261020T015430Z.jar. All 120 routes are byte-for-byte equivalent as parsed JSON before and after r22; no route edit was made.
• The original legacy migration opened 620 events / 241697 journal bytes in 5596 ms and bound at 01:55:09.114.
• Exactly one manual restart was issued using CLI 0.0.20, at 02:04:17.677. The CLI printed Failed: Unknown response format and exited 0, but CN proves restart at 02:04:18.592, drain complete at 19.109. Do not repeat it based on the misleading CLI result. Replacement is lazy: GETs at 02:04:30 triggered start at 31.322, index opened at 38.277 with replayedEvents=0 journalReadBytes=150 rebuildReason=none elapsedMs=5134, bound at 39.486. Bind took 8.164 s from container start; 21.809 s from command start includes the lazy interval. A prior natural start opened in 3592 ms. Zero replay is proven; always-fast startup is not established by these multi-second measurements.
• Right after restart: ExternalBrain home 200 in 2.739746 s; buckets home 200 in 11.699340 s. Documents API returned eight real document names; /doc/baby-sleep.md returned 200. /api/search?q=rocking&limit=10 returned 200 with nameMatches=[], content hit baby-sleep.md, a real snippet and score 2.299211025238037. A separate sleep query verified the name-match half. No reindex/save/write was performed.
• Headless Chromium captured and was used to inspect home and document pages. Both rendered actual content without error text, a blocking overlay or a spurious prompt. PNGs are retained locally at jobs/r22/evidence and on the evidence branch, with no PR upload.

Cold failure and mechanism

Read the millisecond timeline and proposed test.

The original CN request began 01:55:01.873. WUI ready was recorded at 05.255; backend ready at 09.100 and its collected bind line at 09.114. CN returned the 35-byte Service Unavailable: Read timed out body at 35.277, duration 33404 ms. The exact timeout is the localhost HTTP socket from CN's HTTPS facade to the buckets WUI, not the URL RPC backend timeout: deployed CN filename identifies commit 3e198ead, HttpsFacadeProvider.kt:293 sets soTimeout=30_000, line 3461 reads the HTTP status, lines 3842 and 3855 format the observed 503.

A natural full cold chain returned 200 in 27.125975 s at 02:03. Thread dumps showed first bytecode discovery/response reading, then SJVM runtime initialization. No production restart was used to make it cold.

More importantly, at 02:10:09 a naturally cold WUI with an already-running backend reproduced the exact 503 in 34.783911 s. WUI ready was 02:10:13.918 and CN's timeout was 43.924 — 30.006 s later. At 02:10:39 its servlet was waiting on UrlResolver.fetchBytecodeResponseCached, and the bytecode worker was waiting in UrlProtocol2.requestBytecodeViaRelay -> RelayService.sendViaRelay -> RelayStreamController.readBytes. At 02:11:04 the still-running WUI logged persistent RPC reconnect failure; both direct candidate addresses reported closed multiplexed channels of the same root. A later warm GET returned 200 in 8.205050 s. That recovery does not replace the failed cold check.

The proven mechanism is CN's 30-second HTTP read expiring while WUI first-use client bytecode/setup is still pending; the reproduced failure was specifically a relay bytecode response wait. The pre-bind theory is not supported: pre-bind backend timing is unnecessary for the same failure. The original first-dial timestamp is UNKNOWN: original WUI/provider logs contain no such phase, stdout request tracing was off, and the 10000-line in-memory trace had been overwritten. Do not turn that missing evidence into a yes/no answer.

The direct transport closure's cause remains UNKNOWN. The relay read defaults to 30 seconds (UrlProtocol .470 RelayService.kt:5221, read at 5464). The nearby matching resolver source starts a fresh fallback deadline at UrlResolver.kt:5877 and checks it only between candidates; its call at 6922 does not pass remaining time to sendViaRelay. That is a concrete budget propagation gap, but fixing it alone has not been shown to fix the direct fault. No timeout increase or downstream retry is justified.

Source provenance

The deployed WUI's UrlResolver / UrlProtocol2 / SandboxedConnection classes match published resolver .966 byte-for-byte. RelayService / RelayStreamController / Libp2pRpcProtocol match published protocol .470 byte-for-byte.

The provenance ledger records a mismatch: the PR record says .966 came from pre-rebase source 51f2e000, while the .966 binary line positions align with the later merged 1390d0d7b tree, whose coordinate is .976. The binary identity is proven; the exact source tree is not. Keep this caveat when quoting matching-source lines.

Relevant PRs / refs

Deployed and published before merge

Server .17 on url:searchable-bucket: is still built from 9d953788dda88c6b863814ffe8757be6b8424612, unmerged in the PR above. Published coordinate. Deploying from old main could remove this fix. This brief did not authorize merging it. The old rollback jar and /root/searchable-bucket-data.bak-20261019-pre-0.0.17 remain untouched; r17's manifest and digest record are on its evidence branch.

Next steps

1. Re-verify live state. Do not repeat the already-used manual restart, rebuild, republish .17 or edit production under r22 authorization.
2. A follow-on implementation brief should isolate the direct bytecode/connection close through a deterministic public-API reproducer using real isolated CN/backend/WUI instances. Keep both cases: backend already bound and binding held behind a latch. Reproduce the precise stream-close ordering, rather than manufacturing a generic slow server. Include a real relay whose response is clock-controlled, and count public transport work. Retain the actual deployed version matrix: WUI resolver .966 / protocol .470; CN resolver .1320 / protocol .1420; backend resolver .600 / protocol .332.
3. Only after that test fails reliably on old code, fix the layer it isolates. Check whether current upstream already fixes that exact condition. The separate remaining-budget gap should propagate the remaining operation budget through a pending relay wait, without increasing any numerical limit. Do not present that as proven repair of the unknown direct fault.
4. Verify first cold requests and startup work again after a reviewed fix, before completing this handoff. The current brief's verification is partial because cold 503 repeats and multi-second index opening remains a performance finding.

Operational findings

Use /home/helena/bin/coursier. Handoff CLI .8 sometimes reports post-write AmbiguousRpcRequestException / EOF after actions actually applied: claim and clear-blocked were both verified by subsequent reads. Read state before repeating any write. CLI .20 restart has the misleading result noted above. Historical server-log queries returned current records outside the requested until bound; the bounded ring also lacks the historical request. Local-JAR provider-logs is empty; use container-logs and raw provider stdout. Challenge draft is retained rather than auto-submitted because reportchallenge auto-merges a PR, prohibited here.

No source edits, new tests, PRs or merges were made. Source checkouts are clean. Build/dependency JARs, unrelated-route JSON and caches are deliberately excluded from remote evidence. All launched commands have finite deadlines; cleanup and final process audit are recorded in r22 findings.