SPIKE ep0 connections: the leak is felhom-agent's, not the poll rate
gates / gates (push) Successful in 14s

R-341's first dated check, taken at +46.2 h: fd 17 -> 405 over 166,251 s
= 201.6/day. Pre-registered range was 370-450; observed 388. UNCHANGED,
as predicted. CLOSE-WAIT is 0 -- absent entirely, not merely flat.

Q1: exactly two peers, 194 each, no third party.
Q2: outcome (a). ep0 388 = 194 + 194 on the boxes, twice, and the four
    new sockets carry the same source ports on both sides. 0 closed in 31 min.

The finding: all 388 are held by felhom-agent. pvestatd and
proxmox-backup-client made 162,404 requests and leaked zero. Mechanism is
a per-cycle http.Transport with a zero-value IdleConnTimeout that nothing
ever closes (internal/pbs/client.go:56, main.go:1486). R-336's premise
does not survive this -- cutting the poll rate would have fixed nothing.

Q3 NOT measured: Phase C held at STOP 1, prediction pre-registered first.

Part 0 captures the due-checks gate's first conviction on a real overdue
date (rc=1, names R-341, sole failure among 10 gates). Row cleared at
Part 4, after the result was recorded in R-341, not to make a push work.

New: R-344 (the transport leak), R-345 (hub/Makefile pushes :latest),
R-346 (ActiveEnterTimestamp reads 5h56m early -- NRestarts is still 0).
This commit is contained in:
2026-08-20 10:41:37 +02:00
parent 848368ec38
commit 19672e685e
22 changed files with 1330 additions and 8 deletions
+162
View File
@@ -0,0 +1,162 @@
# REPORT — SPIKE: who holds ep0's connections open (2026-08-20)
**Status: STOP 1 reached. Parts 0, 1 and 2 are complete. Phase C (Part 3) has NOT been run — it is your
decision, below.** Everything done in this session was **read-only**. No machine was changed.
---
## ⛔ The decision waiting on you
Phase C wants one overnight window on `demo-hp`. **The measurement found something that changes which
mutation is worth running**, so there are two versions of it. Both are one mutation on a Tier-0
disposable box, both arm a dead-man timer first, both are unattended.
| | **Option A — stop `pvestatd`** (what the spike prompt specifies) | **Option B — stop `felhom-agent`** (what the evidence now points at) |
|---|---|---|
| what it tests | the original Q3: does the leak track the request rate? | does the leak track **our agent's** cycle? |
| predicted result | **null** — leak unchanged at ~201.6/day, ~84 descriptors in 10 h, split evenly ~42/~42 | leak **halves** — ~101/day, ~42 descriptors in 10 h, split ~42 from `demo-felhom` and **~0** from `demo-hp` |
| what it buys | **falsification.** If the leak *did* halve, the whole Part-1/2 attribution is wrong and must be withdrawn | **confirmation by a second, independent route.** A near-zero contribution from the quietened box is decisive |
| cost if the attribution is right | a confirmed null — real evidence, but no new information beyond what Parts 1–2 already show | the sharpest possible confirmation |
| risk | none beyond the window: `pvestatd` is PVE's stats daemon; the box keeps running, backups are not due until ~08-25 | slightly higher: the agent is our own product on the box. It would stop reporting to the hub for the window, and the hub's staleness watch may notice |
**I would run Option A, tonight.** Two reasons. It is the mutation the prompt authorises, and standing
rule 2 says exactly one mutation exists in this run — substituting one is my call to propose, not to
make. More importantly, **A is the falsification test and B is the confirmation test**, and the
attribution is already confirmed twice over (socket ownership on the boxes, and the access-log user
agent, by completely independent routes). A test that can prove me wrong is worth more right now than a
third test that can only agree with me.
**What I need from you: "A tonight", "B tonight", "at the weekend", or "skip it".** If you pick B I will
need you to say so explicitly, because it is a second mutation the prompt does not authorise.
---
## What I did, and what it found
### Part 0 — the dated-check gate's first real conviction, captured before anything else
The 2026-08-19 row was one day overdue. Every conviction this gate had produced before came from a
fixture or a `FELHOM_GATE_TODAY` override; **this is its first firing on a real overdue date in the live
register**, and it behaved correctly:
- **exit code 1** — a verdict, not a crash (2) and not a pass (0);
- the message **names R-341 and the days overdue** (`R-341 due 2026-08-19 1 day(s) OVERDUE`), so the
exit code is not doing the work alone — which is the failure mode this gate's own red-proof fell into
on 18 August;
- inside `repo_gates.py` it is the **only** conviction: 9 gates OK, `CONVICTED: due-checks`.
Captured verbatim in `part0-due-checks-gate.txt` and `part0-repo-gates.txt`. The row was **not** cleared
to make the push work — it was cleared at Part 4, after the measurement existed and its result was
recorded in R-341, which is the sanctioned order.
### Q0 — R-341's first dated check: the slope is UNCHANGED
Precondition passed: PID still **551655**, `NRestarts=0`, so the elapsed window is valid.
**fd 17 → 405 over 166,251 s (46.18 h) = 201.6 fd/day**, Poisson 2σ 181.2–222.1.
The prediction was pre-registered before the reading: **370–450**. **Observed 388.**
Verdict: **unchanged**, the expected result, and not a failed upgrade.
This settles the check on a window **88× longer** and a descriptor count **97× larger** than the
30-minute windows the original answer rested on. Uncertainty drops from roughly ±50% to ±5%.
**Composition:** ESTAB 0 → 388, and **CLOSE-WAIT is 0 — absent from the histogram entirely.** The
incident document's original emphasis on `CLOSE-WAIT` is not merely the minority story; on this proxy
generation that state does not occur at all.
Runway to the 65536 ceiling: **~323 days (~2027-07-09)**.
### Q1 — who is at the far end: exactly the two demo boxes, 194 each
No third peer. Outcome (c) excluded. The identity is read from the API token name on every access-log
line, not inferred from the address. `lsof` confirms the leak is sockets and nothing else: 390 of 405
descriptors are TCP.
**Persistence (31-minute diff of full 4-tuples): 388 in both readings, 0 closed, 4 new.** Not one socket
closed. All carry keepalive timers with `retrans=0` — the far ends are answering, so these are not
half-open sockets.
### Q2 — outcome **(a)**, confirmed twice, exactly
| instant | ep0 | `demo-felhom` | `demo-hp` | sum |
|---|---|---|---|---|
| 08:02:39 / 08:04:37Z | **388** | 194 | 194 | **388** |
| 08:33:42 / 08:34:01Z | **392** | 196 | 196 | **392** |
And the four sockets that appeared between the readings carry **the same four source ports** on ep0 and
on the boxes. Both sides hold every connection.
### The finding nobody predicted: the leak is ours
`ss -tnp` on the boxes names the owner of **194 of 194** on each: **`felhom-agent`**, one PID per box.
Zero are held by `pvestatd`. Zero by `proxmox-backup-client`.
ep0's access log says the same thing by a completely independent route:
| who | requests in the window | descriptors leaked |
|---|---|---|
| `libwww-perl` (pvestatd) | 81,192 | **0** |
| `proxmox-backup-client` | 80,061 | **0** |
| `Go-http-client` (**our agent**) | 811 (of which **387** `/snapshots` calls) | **388** |
**One leaked socket per agent `/snapshots` call, within one.** 99.5% of the traffic produces 0% of the
leak.
**Mechanism, named from source** — `felhom-agent/internal/pbs/client.go:56-60` builds
`&http.Transport{TLSClientConfig: tlsCfg}` as a composite literal, so `IdleConnTimeout` is the zero value
(= no limit; `http.DefaultTransport` sets 90 s and a literal does not inherit it), and
`cmd/felhom-agent/main.go:1486` builds **a fresh client every cycle**, as its own doc comment states.
`CloseIdleConnections`, `IdleConnTimeout` and `MaxIdleConns` appear **nowhere in the agent repo**.
Cadences reconcile without fitting: 900 s hub poll (184.7 cycles) + 6 h verify cadence (7.7) = 192.4
predicted against **194 observed per box**.
**No fix is proposed** — the spike-first gate forbids it, and the spec is a separate task. Filed as
**R-344**, with the open design questions listed rather than pre-answered.
### Control window: clean
No reboots (ep0 up 17 d, boxes up 10 d), no daemon restarts (`NRestarts=0`), no agent restarts, **no
request-rate gap** (3,536–3,553 per hour, every hour), **no HTTP errors at all** (every response 200
except 8 expected 101s), no tunnel flap. **No backup ran inside the window** — the last offsite protocol
upgrades were 08-18 03:57/03:58Z, *before* `t0`, and the tier is weekly with the next run due ~08-25, so
**tonight's window is also clear of one.** Routine verify jobs and restore-test reads did occur; they are
1.2% of traffic and are already counted inside the 194/box reconciliation.
**Hub:** no `*_unreachable` or `*_recovered` event; the PBS-DR gauge refreshes on schedule and host
reports land from both boxes. **Honest limit:** the hub pod is 39 h old, so hub-side logs cover 36.6 of
the window's 46.2 hours; the first 9.6 h rests on ep0's own evidence.
---
## Register changes
- **R-341** — first check recorded (taken at **+46.2 h, not +24 h**; the delay was pure elapsed time and
the longer window is stated as a **better** measurement, not a degraded one). **2026-08-19 row removed**
from `DUE-CHECKS`; 2026-08-25 kept, with the Phase-C perturbation quantified against it (**~3%** shift
on the 7-day slope even under the hypothesis we expect to be false — the reading stays usable).
- **R-336** — mechanism named; **premise corrected and re-ranked**. Its recorded next step would have
produced a null result and read as a failed fix. The poll rate is now a scaling/cost item; the leak fix
is R-344. **Q3's proportionality verdict is explicitly NOT recorded** — Phase C has not run.
- **R-340** — noted which of its wanted observations this run already produced, so the health-op task
reuses them rather than measuring a protected machine a third time. Only the loopback probe is still
owed.
- **R-344 (new)** — the agent's per-cycle transport leak. READY (S).
- **R-345 (new)** — `hub/Makefile` lines 21–22 tag and push `:latest`, which two rule files forbid.
READY (XS).
- **R-346 (new)** — `ActiveEnterTimestamp` reads 5 h 56 m early for this proxy generation (the upgrade
re-exec'd rather than restarted, so `NRestarts` is still 0). Anchoring a slope on it gives ~12% low.
READY (XS).
## Deliverables
- `documentation/audits/SPIKE-ep0-established-connections-2026-08-20.md` — the findings.
- `documentation/audits/evidence-ep0-established-connections-2026-08-20/` — 11 raw evidence files,
including the **pre-registered Phase C prediction**, committed before the mutation exists.
- `documentation/backlog/OPEN-ITEMS.md`, `STATUS.md` — as above.
## What is inconclusive
**Q3 is unmeasured**, by design. Everything stated about proportionality is a labelled prediction. Also
unexplained: why the two boxes' leaked counts are *exactly* equal at two separate instants rather than
merely close. And whether restore-test reader connections leak too was not separated out (≤2% of the
total, inside the noise).