# netlab-manager forensics — host 198.199.106.165 — 2026-07-28
Forensics dir on host: `/root/netlab-mgr-forensics-20260728/` (all captures still running)
---
## HEADLINE
1. **The reported premise is wrong.** `netlab-manager-server.jar` is **not** restart-churning. It is a single
process (pid 560505) that has been up continuously for **~30 hours** (since Jul 27 02:33:53 UTC).
No OOM, no `System.exit`, no CN kill, no kernel OOM kill.
2. **A different service *is* churning** — `production-health-server.jar` runs **two concurrent instances**,
one of which respawns every ~60–75 s. That is a ContainerNursery reaper/duplicate-spawn defect and is
a real CPU consumer, but it is unrelated to NetLab.
3. **The NetLab CI failures are real and have a different mechanism**: the manager reuses a
`PersistentRpcConnection` whose underlying libp2p stream has already been **closed locally**. The next
write throws `java.io.IOException: Stream closed`, which is converted into a non-retryable
`AmbiguousRpcRequestException`. **The TCP connection to the worker droplet stays ESTABLISHED the whole
time** (proven by packet capture). This is a stale-stream-reuse defect in the upstream
`foundation.url` transport (UrlProtocol / UrlResolver), not a network fault and not a worker crash.
4. **No action taken.** Nothing was restarted, redeployed, resized or deleted. The fix requires an upstream
code change, so per the mission constraints I stopped at reporting.
---
## Step 1 — CAPTURE (done first, still running)
Container stdout/stderr on this host are **not** deleted fds; they are real files. Live `tail -f` captures
plus samplers were started at 08:10:08 UTC into `/root/netlab-mgr-forensics-20260728/`:
| file | source |
|---|---|
| `mgr-560505-stdout.log` | `/proc/560505/fd/1` → `.../container-logs/netlab-manager-server-43788c5e.stdout.log` |
| `mgr-560505-stderr.log` | `/proc/560505/fd/2` → `.../container-logs/netlab-manager-server-43788c5e.stderr.log` |
| `cn-4165366-stdout.log`, `cn-4165366-stderr.log` | CN pid 4165366, both fds → `/root/ContainerNursery/cn-deploy-20260726T235338Z.log` |
| `ts-diag.log` | timestamped stream of `NETLAB-FORWARD-DIAG` / READY / delete events (`ts-capture.sh`) |
| `churn-young-procs.log` | 2 s sampler of every java proc younger than 120 s (`churn-sampler.sh`) |
| `tcp-close-all.log`, `tcp-close-events.log` | tcpdump FIN/RST captures |
| `worker-ip-map.txt` | 1469 worker-UUID → droplet-IP mappings extracted from the manager log |
| `peers.txt`, `young-all-procs.raw` | socket-peer and short-lived-process samples |
Full-history logs (not truncated, preserve these): the four `container-logs` files above, plus the
**timestamped** JSON route log `/root/ContainerNursery/data/container-logs/url_netlab-hosted_.stdout.log`
and its rotation `url_netlab-hosted_.stdout.20260727153843-20260728035919.log`.
No new heap dumps were produced during the investigation; the two existing ones (Jul 27) are untouched.
---
## Step 2 — DEATH MECHANISM: there is no death
### OBSERVED
```
560505 4165366 106552s 18.3%CPU 749928KB Mon Jul 27 02:33:53 2026
java -Xmx384m -XX:MaxMetaspaceSize=128m -XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/root/ContainerNursery/heapdumps -XX:+ExitOnOutOfMemoryError
-jar /root/ContainerNursery/apps/netlab-manager-server.jar ...
```
- Exactly **one** process matches `netlab-manager-server.jar`; PID never changed across the whole session.
- Exactly **one** container-log generation (`netlab-manager-server-43788c5e.*`). CN opens a new log per
container instance, so there has been no restart in 30 h.
- JVM uptime from `jcmd`: **107 676 s** — corroborates the 30 h independently of `ps`.
- No new heap dumps since Jul 27 07:36. Disk 90 % used but **5.2 G free** — the dump path is not blocked.
- `dmesg`/OOM: no kernel OOM kill of this process; `-XX:+ExitOnOutOfMemoryError` never fired.
- Heap is healthy and **not** leaking: old gen steady at **54.3 %** of a 384 M heap across the observation
window; metaspace 35 M committed of a 128 M cap. The Jul-27 gossip-retention leak fix is holding.
### OBSERVED — why the earlier sample *looked* like churn
```
08:10:47 ns_last_pid=511396 /proc/stat processes: +363 in 5 s
08:10:53 ns_last_pid=511756 => ~73 fork/clone per second, sustained
08:10:58 ns_last_pid=511979
```
At ~70 PIDs/s the PID counter advances ~2000 every 30 s, so PID *numbers* in any two samples 30 s apart look
completely different. (Most of this is `clone()` for JVM threads across ~20 co-resident JVMs — a 0.3 s
resolution sweep of all short-lived processes found no process-spawn storm.)
### OBSERVED — the actual churner is production-health-server, not netlab-manager
```
08:20:06 pid=543542 age=58 cpu=82.4 08:21:48 pid=543542(age=160) pid=548381(age=44)
08:20:06 pid=544911 age=29 cpu=46.2 08:22:08 pid=543542(age=181) pid=548381(age=65)
08:20:24 pid=544911 age=46 (then died) 08:22:18 pid=543542(age=190) <-- 548381 gone
```
Three distinct PIDs for the same service inside ~12 minutes, with **two instances alive simultaneously**.
This is the ContainerNursery duplicate-spawn / failed-reap pattern. Combined it burns ~130 % CPU.
**INFER:** this is most likely what was sampled and misattributed to netlab-manager.
---
## Step 3 — JAR PROVENANCE
### OBSERVED
```
2026-07-27 02:33:38 58075136 B netlab-manager-server.jar
sha256 9c0ca9e12a72196ced1917fca649d6aea72991261c4f1220e5fab55b38783296
2026-07-22 22:16:56 57538032 B netlab-worker-server.jar
sha256 846cadc5ae02374a4addd6d1e6ebefc3024caf09fa97105bcca96c2fba195a5b
```
- The manager jar's mtime (02:33:38) is 15 s before the process start (02:33:53). **The Jul-27 fixed build is
genuinely the one running.** No rollback, no stale artifact on the manager side.
- **However the worker jar is 5 days older, and the two ends run different transport builds:**
| class | manager jar | worker jar |
|---|---|---|
| `foundation/url/resolver/UrlProtocol2.class` | 581 869 B, CRC `3cacd644` | 483 373 B, CRC `79255c71` |
| `foundation/url/resolver/UrlResolver.class` | 52 794 B, CRC `7cf8ed0b` | 51 187 B, CRC `3c7b7900` |
| classes under `foundation/url/resolver/` | 750 | 646 |
The manager uploads `--worker-jar-path .../netlab-worker-server.jar` to every droplet, so **every worker in
the fleet runs a ~100 KB-smaller, 5-day-old UrlProtocol2** missing whatever landed between Jul 22 and Jul 27.
**INFER:** a contributing factor worth eliminating, but not proven to be *the* cause.
---
## Step 4 — WHAT IS ACTUALLY BREAKING NETLAB CI
### OBSERVED — scale and shape
- `uploadFile` requests served in 30 h: **117 359**; errors: **3 546** → **3.02 % failure rate**.
- `Error handling 'logs'`: 529; `'exec'`: 22. `NETLAB-FORWARD-DIAG` failures: 3 415
(logs 2 444, exec 567, applyStatus 319, applyAsync 27, …).
- Manager-side retry: `attempt=1-of-2 (before reopen)` 2 953 vs `attempt=2-of-2 (after reopen)` 546 →
**~82 % recover on immediate reopen.** The remote peer is alive; only the connection object is dead.
- Sustained all night, 10-minute buckets: 76 → 304 → 503 → **778** → 736 → 439 → 565 events. Chronic, worsening.
- `"exhausted five attempts"` appears **nowhere** in the manager logs → that wording is emitted by the
**client** (netlab CLI / CI harness) after its own 5 retries all land inside one broken window.
### OBSERVED — the workers are healthy; they are not crashing
Logged into live worker droplets with `/root/.ssh/id_ed25519`:
- `68.183.51.105` (worker 008c1b37): up 10 min, 1491/3911 MB used, worker JVM alive, happily serving
`exec`/`logs`. Whole log contains **one** `StacklessClosedChannelException` and nothing else.
- `165.227.214.59` (worker 16365831): up 4 min, 437/3911 MB used, streaming `uploadFile` parts fine.
Again exactly **one** exception in the entire log.
- Worker JVMs run `java -jar /opt/netlab-worker/worker.jar` with **no `-Xmx` and no OOM dump flags**
(a separate observability gap worth fixing, but they are not OOMing — ~225–240 MB RSS on 3.9 GB boxes).
### OBSERVED — TCP is never torn down
90 s of `tcpdump` for FIN/RST across all non-hub peers, while the manager was logging forward failures:
**6 packets total, every one of them loopback/docker-internal** (`10.234.34.1`, `172.17.0.1`).
**Zero FIN/RST to any worker droplet IP.**
```
2026-07-28 08:26:01 IP 10.234.34.1.44605 > 10.234.34.1.48554: Flags [F.]
2026-07-28 08:26:56 IP 172.17.0.1.41291 > 172.17.0.1.40984: Flags [R.]
```
(Caveat: one row in my correlation table showed `finrst_packets=6` for worker `a2ca23f6`; that is a
**false match** — its IP was UNKNOWN so the grep pattern was empty and matched every line. Not a finding.)
### OBSERVED — the innermost cause is a *local* stream close on the WRITE path
371 occurrences of `Original write failure: java.io.IOException: Stream closed`, whose stack is:
```
java.io.IOException: Stream closed
at foundation.url.protocol.NettyStreamController$NettyOutputStream.write(Libp2pHostFactory.kt:3230)
at foundation.url.protocol.Libp2pRpcProtocol.writeMessage(Libp2pRpcProtocol.kt:1186)
at foundation.url.resolver.PersistentRpcConnection.ambiguousWriteFailure(UrlResolver.kt:16899)
at foundation.url.resolver.PersistentRpcConnection.doSendRequest(UrlResolver.kt:17139 / :17148)
at foundation.url.resolver.PersistentRpcConnection.sendRequest(UrlResolver.kt:16982/16990/17000/17006)
at netlabmanager.WorkerClient.forwardRequest(WorkerClient.kt:144)
at netlabmanager.NetLabManagerRpcHandler.forwardToReadyWorker(NetLabManagerRpcHandler.kt:513)
at netlabmanager.NetLabManagerRpcHandler.handleUploadFile(NetLabManagerRpcHandler.kt:488) [or handleLogs:456 / handleExec:451]
```
And 7 929 occurrences of the read-side twin, whose cause always terminates at the reader thread:
```
foundation.url.resolver.UrlResolutionException: Persistent RPC connection to service
'netlab-worker-<uuid>' was closed while requests were still pending.
at foundation.url.resolver.PersistentRpcConnection.createReaderThread$lambda$4(UrlResolver.kt:16524)
```
Reconnect machinery exists and partly works, but also fails: `Failed to reconnect persistent RPC
connection` ×103, `is already reconnecting and did not complete within Nms` ×26,
`was interrupted while reconnecting` ×19.
### THE MECHANISM (stated plainly)
> A `PersistentRpcConnection` to a netlab worker is handed out for a new request **after its underlying
> libp2p `NettyOutputStream` has already been closed locally**. The first write on that stale stream throws
> `java.io.IOException: Stream closed` from `NettyStreamController$NettyOutputStream.write`
> (Libp2pHostFactory.kt:3230). `PersistentRpcConnection.ambiguousWriteFailure` (UrlResolver.kt:16899)
> classifies it as *ambiguous* — "the write had begun, the remote handler may already have run" — so it is
> deliberately **not replayed**, and the caller sees a hard failure. The TCP connection to the droplet
> remains ESTABLISHED throughout, and the worker never sees or logs anything.
Evidence that pins it, and what each item rules out:
| evidence | rules out |
|---|---|
| `IOException: Stream closed` thrown from the local `NettyOutputStream.write` | remote reset / network drop |
| 0 TCP FIN/RST to any worker IP in 90 s of capture | network fault, droplet teardown, firewall |
| worker logs contain 1 exception total; worker JVMs alive, low RSS | worker crash / worker OOM |
| 82 % of failures succeed on immediate reopen | worker unreachable, DNS/routing, droplet destroyed |
| manager old gen flat at 54 %, no dumps, 30 h uptime | manager OOM / leak / restart |
### Hypotheses I tested and REFUTED (stated so they are not re-investigated)
- **Idle-TTL reaper killing live environments — NO.** `ReconcileService` reaps only genuinely idle envs
(`idle for 1 910 117…2 076 512 ms >= 1 800 000 ms TTL`), and for every reaped env I checked, requests
after the reap = **0** (`url-iro-2653650801897` 40 before/0 after; `url-impair-1420467656332` 124/0;
`url-p2p-902686459872` 91/0). The reaper is behaving correctly.
- **GC pauses as the primary cause — NO.** Manager GC over 29.9 h: YGC 23 331 / 1 645.96 s,
FGC 104 / 156.30 s, total 1 802 s = **1.67 % of wall time**. Only 104 full GCs against 3 546 upload
failures — the numbers are three orders of magnitude apart. (Worth noting anyway: **1.50 s average full-GC
pause** and **70 ms average young-GC pause** on a 76 M young gen is poor, a consequence of SerialGC on a
heavily loaded host — but it cannot explain the failure volume.)
- **Socket/fd leak in the manager — NO.** 112→130 ESTAB across samples, per-hub counts stable (24→22, 25→26);
165 fds against a 1 048 576 limit; 165–169 threads.
- **Manager thread starvation — NOT SUPPORTED.** Thread dump: 85 WAITING, 32 TIMED_WAITING, 30 RUNNABLE,
1 BLOCKED, 41 libp2p/reader threads. No pile-up.
---
## Host load attribution (step 4)
### OBSERVED
Load average 70–79 (later 41) on **8 cores**; 11.7/16 GB used. Top consumers:
| pid | %CPU | what |
|---|---|---|
| 4165366 | 160 % | **ContainerNursery itself** (`-Xmx768m` G1, 32 h up) |
| 543542 + 548381 | ~130 % combined | **production-health-server.jar ×2 concurrent instances** (duplicate spawn / failed reap) |
| 949412 | 56 % | HardwareControlFabric daemon |
| 2588307 | 44 % | buildtest-wui (`-Xmx2048m`) |
| 498168 | 36 % | handoff-service-server |
| 370203 / 469555 / 3878386 | 30–32 % | github-watchman, performancetest-wui, kotlin-build-ci |
Plus ~15 more `-Xmx128m` containers. **INFER:** the load is the aggregate of ~20 co-resident JVMs, with CN
and the duplicated production-health instances as the two largest single contributors. The duplicate
production-health instance is straightforwardly wasted CPU and is the one clearly-defective consumer.
Also worth flagging: `[ReconcileService] phantom-pruning pass complete: pruned 0, kept 14…27
(**76–97 live droplet(s) on the account**)`. The manager tracks 14–27 environments while the DO account
carries 76–97 droplets. The account is shared with buildtest so this is **not** proof of a netlab leak, but
the gap is large enough to be worth a dedicated check against the known droplet-limit ceiling.
---
## Step 5 — ACTION TAKEN: NONE (deliberately)
The mechanism is an **upstream defect in `foundation.url` (UrlProtocol / UrlResolver)** — a connection
object outliving its libp2p stream. Fixing it requires a code change, so per the mission constraints I did
**not** hand-patch, restart, or redeploy anything. Restarting the manager would also have destroyed the live
evidence and killed ~20 in-flight CI environments for no benefit — it is not the faulty component.
### Recommended fixes, in priority order
1. **Upstream (the real fix).** In `PersistentRpcConnection`, validate stream liveness before handing a
pooled connection to `doSendRequest`, and treat a *pre-write* `IOException: Stream closed` as a
**retryable** condition rather than an ambiguous one — no bytes reached the wire, so replay is safe.
The current code at `UrlResolver.kt:16899` (`ambiguousWriteFailure`) cannot distinguish "stream was
already closed before I wrote anything" from "transport failed mid-write", and conservatively refuses to
replay both. That conflation is what turns a recoverable stale-connection event into a CI failure.
Repro target: concurrent `uploadFile` calls through a `PersistentRpcConnection` whose stream is closed
between checkout and write.
2. **Rebuild and redeploy `netlab-worker-server.jar`** so both ends run the same transport build
(currently Jul 22 vs Jul 27). Cheap, and removes a whole class of skew from the picture.
3. **ContainerNursery duplicate-spawn / failed reap for production-health-server** — two live instances of
one route, one respawning every ~60–75 s. Separate defect, real CPU cost, same family as the documented
CN zombie-process case study.
4. **Give worker JVMs `-Xmx` + `-XX:+HeapDumpOnOutOfMemoryError`** — currently unbounded and undiagnosable.
### Precise missing evidence (the one thing I could not establish)
I proved the write-side failure is a **locally** closed stream. What I could **not** establish is *what
closes that stream first* — i.e. whether the muxed libp2p stream is reset by the worker over the still-open
TCP connection, or torn down locally by the manager's own UrlProtocol2 (idle/prune/keepalive path). TCP
capture cannot see it because it happens inside the muxed session. Deciding it needs one of:
- DEBUG-level logging on `foundation.url.protocol.NettyStreamController` / `Libp2pRpcProtocol` on the
manager for a few minutes (would name the closer directly), or
- a yamux/mplex-decoding packet capture on one worker connection, or
- a targeted upstream unit test around `PersistentRpcConnection` stream-lifecycle vs. checkout.
Everything else in the chain is established by direct observation above.