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).
+13 -3
View File
@@ -1,7 +1,7 @@
# STATUS — what works, what's broken, what's next
**Updated 2026-08-18 (afternoon — a listening socket that served nobody, a rehearsal upgrade that changed
nothing, and a new install that is finally current).**
**Updated 2026-08-20 (morning — we looked at who was actually holding the off-site box's connections
open, and it turned out to be us).**
> **A view, not a source.** `documentation/backlog/OPEN-ITEMS.md` is the authority; this page restates
> part of it in plain words, and **nothing may exist only here**. **Items, not paragraphs. One screen.**
@@ -116,6 +116,14 @@ record with no machine** — created 13 August, no host, no backups, nothing to
alarm. **Corrected later the same morning: my first estimate of how fast it leaks was too
optimistic by about 2.5×** — measured properly it is under a year to the new ceiling, not two years.
A deadline, not a comfort.
- **The leak is OURS, not Proxmox's, and asking fewer questions would not have fixed it** (R-344, found
2026-08-20). We finally looked at who was on the other end of the stuck connections. Every single one
belongs to **our own agent** on the two demo machines — it opens a connection to the off-site box on
each 15-minute cycle and never closes it, and neither does the box. The two Proxmox pollers that make
99.5% of the traffic leak **nothing at all**. So the plan recorded under R-336 — turn the question
rate down, then watch the count stop climbing — **would have changed nothing and looked like a failed
fix.** The count still says about a year to the ceiling. **Nothing is broken today**; this is a
deadline we now know where to aim at. *(register: R-344, and R-336 re-ranked)*
- **The off-site box was updated, and it did not help — as expected** (R-341). On your ruling we
installed the newer backup software for the practice, having first read its release notes and found
**nothing** about the fault we have. The update went cleanly and everything works, but the leak
@@ -155,7 +163,9 @@ record with no machine** — created 13 August, no host, no backups, nothing to
## Working on next
`demo-hp` is yours this evening — **this session did not touch it**. After that: the three remaining
**One decision is waiting for you, at the top of `REPORT-spike-ep0-connections.md`:** whether to run the
overnight measurement window on `demo-hp` tonight, and which of two versions of it. Nothing was changed on
any machine in this session — every reading was read-only. After that: the three remaining
R-264 readers, now that one has been built and we know what one costs; R-317 (one line in the agent);
R-327 (decide what the naming claim's status should be); then the 2026-08-09 batch (R-279 … R-292),
still untriaged against everything since.
@@ -0,0 +1,323 @@
# SPIKE — who holds ep0's connections open, and does the leak track the poll rate?
**Run:** 2026-08-20 08:01–08:35 UTC, read-only throughout. **Phase C (the one mutation) has NOT been run** — it is
held at STOP 1 for the operator's window decision.
**Evidence:** `evidence-ep0-established-connections-2026-08-20/`, one file per step.
**Supersedes the plan in** `SPIKE-ep0-established-connections.md` (issued 2026-08-18, never run).
> **Headline, and it is not the headline the spike expected.**
> The leak is **ours**. Every one of the 388 leaked descriptors on ep0 is an established connection held
> open by **`felhom-agent`** on the customer boxes — one per PBS poll cycle, never closed on either side.
> `pvestatd` and `proxmox-backup-client` made **162,404 requests** in the same window and leaked **zero**.
> R-336's premise — that cutting the ~85,000/day poll rate is the leak fix — **does not survive this
> measurement.** The poll rate is a separate (real) problem; it is not what is consuming descriptors.
---
## Q0 — R-341's first dated check: has the fd slope changed since the PBS 4.2.5-1 upgrade?
### Answer: NO. Unchanged, and now measured over a window 88× longer than the one it replaces.
**Precondition passed.** `MainPID = 551655`, `ps -o lstart` = `Tue Aug 18 09:51:04 2026`, `NRestarts = 0` on
both `proxmox-backup-proxy` and `proxmox-backup`. The proxy generation that carries `t0` is the one that was
read. The elapsed-window measurement is valid.
| | value |
|---|---|
| `t0` | fd **17**, ESTAB 0, 2026-08-18 **09:51:22Z**, PID 551655 |
| reading A | fd **405**, ESTAB **388**, CLOSE-WAIT **0**, 2026-08-20 **08:02:13Z**, PID 551655 |
| elapsed | **166,251 s** = 46.181 h = 1.9242 d |
| delta | **+388 fd** |
| rate | **201.6 fd/day** (8.40/h) |
| Poisson on n=388 | ±19.7 counts → **±10.2/day (1σ)**, ±20.5/day (2σ) → **181.2 … 222.1 /day** |
| limits | soft/hard **65536 / 65536** — the drop-in survived the upgrade |
| listener | `LISTEN Recv-Q 0 Send-Q 1024` — accept queue empty, nothing wedged |
**Verdict against the pre-registration**, quoted from the spike prompt §2 so it is visible beside the result:
> *"Predicted range: roughly **370–450** … A reading anywhere in **330–490** confirms an unchanged rate …
> **In range** → unchanged rate. This is the EXPECTED result, consistent with the changelog containing no
> mechanism to change it. It is not a failed upgrade."*
**Observed: 388.** In range, and close to the centre. The rate is **unchanged** since the upgrade. This is the
expected result and it is recorded as such — not as a success and not as a failure of the upgrade, which was
run for rehearsal value and never claimed to fix anything.
For comparison, on the identical method: **183/day** (31 min, pre-upgrade), **200/day** (5.64 h, pre-upgrade),
**225/day** (32 min, post-upgrade). This window carries **97× the descriptor count** of the 31-minute window,
so its uncertainty is ±5% rather than ±50%.
### Composition — the split, which is what says *which* leak it is
```
t0 fd 17 ESTAB 0 CLOSE-WAIT 0
reading A fd 405 ESTAB 388 CLOSE-WAIT 0 17 + 388 = 405, exactly
```
**`CLOSE-WAIT` is absent from the `ss` histogram entirely — 0, not merely flat.** 100% of the growth is
**established** connections on `:8007`. This closes the question the incident's own correction block opened:
the mechanism is *connections the proxy never reaps*, and `CLOSE-WAIT` is not merely the minority half, it is
**not present at all** on this proxy generation.
### Runway
From fd 405 at 201.6/day to the 65536 soft limit: **≈ 323 days**, i.e. around **2027-07-09**. Under a year.
A deadline, not a comfort — unchanged in character from what R-341 recorded.
---
## Q1 — who is at the far end?
### Answer: exactly the two demo boxes, in a dead-even split. No third peer. Outcome (c) is excluded.
At 08:02:39Z, `ss -tn state established '( sport = :8007 )'`, peer histogram:
| peer | connections | identity |
|---|---|---|
| `10.77.0.2` | **194** | `demo-felhom` (host `felhom-pve`) — token `felhom@pbs!demo-felhom` |
| `10.77.0.3` | **194** | `demo-hp` (host `felhom-host`) — token `felhom@pbs!demo-hp` |
The identity is not inferred from the address: ep0's own access log carries the API token name on every line
(`::ffff:10.77.0.3 - felhom@pbs!demo-hp …`), and the mapping is one-to-one across the whole file.
**194 / 194 is not approximately even — it is exactly even**, which is itself a finding: whatever opens these
is a per-box periodic task running the same schedule on both, not traffic proportional to anything the boxes
differ in.
### Descriptor-type breakdown (1.3)
`lsof -np 551655`, which distinguishes sockets from files, pipes and eventfds so a "leak" that is not sockets
gets caught here:
| type | count |
|---|---|
| **IPv6 (TCP)** | **390** |
| REG (log files, rrd journal, datastore lock) | 32 |
| unix | 7 |
| a_inode (epoll ×2, eventfd ×1) | 3 |
| DIR | 2 |
| CHR (`/dev/null`) | 1 |
`lsof … | grep -c TCP` = **390** = 388 established + 1 listener + 1 other. The independent `/proc/<pid>/fd`
link-target histogram agrees: **397 sockets** (390 TCP + 7 unix), 9 regular/anon fds. **The leak is sockets,
and the sockets are TCP on :8007.** Nothing else is growing.
### 1.4 — persistence: are they long-lived, or churn?
Full 4-tuples diffed between reading A (08:02:39Z) and reading B (08:33:42Z), **1,843 s apart**:
| | count |
|---|---|
| sockets in reading A | 388 |
| sockets in reading B | 392 |
| **in BOTH — long-lived** | **388** |
| **only in A — closed during the interval** | **0** |
| only in B — new arrivals | **4** (2 per box) |
**Not one socket closed in 31 minutes.** There is no churn to separate from the leak: every established
connection on this proxy is the leak. The 4 arrivals over 1,843 s = 187.5 fd/day, consistent with the
elapsed-window 201.6/day within Poisson on n=4.
**Idle age and liveness.** All 392 sockets carry a TCP keepalive timer and **all 392 report `retrans=0`** —
the far end is answering keepalive probes. These are not half-open sockets whose peer went away; they are
mutually held, live, idle connections. That, on its own, points at outcome **(a)** and Part 2 confirms it.
---
## Q2 — do the boxes hold them too?
### Answer: **outcome (a)** — both sides hold every connection, and the two counts match exactly. Twice.
| instant (UTC) | ep0 ESTAB on `:8007` | `demo-felhom` ESTAB to `10.77.0.1:8007` | `demo-hp` | sum |
|---|---|---|---|---|
| reading A — ep0 08:02:39, boxes 08:04:37/38 | **388** | **194** | **194** | **388** |
| reading B — ep0 08:33:42, boxes 08:34:01/02 | **392** | **196** | **196** | **392** |
Two independent paired readings, both exact. And the confirmation is tighter than the totals: the **four new
sockets** that appeared on ep0 during the persistence window carry **the same four source ports** the boxes
report as new —
```
ep0 new: 10.77.0.2:45620 10.77.0.2:53226 10.77.0.3:37554 10.77.0.3:46214
demo-felhom new: 10.77.0.2:45620 10.77.0.2:53226
demo-hp new: 10.77.0.3:37554 10.77.0.3:46214
```
Both boxes also closed **zero** sockets in the same interval (A=194, B=196, closed=0, new=2, on each).
**This is not a hedge between two outcomes.** Outcome (b) — half-open sockets ep0 never noticed — is
excluded by both the matching counts and the `retrans=0` keepalives. Outcome (c) is excluded by Q1.
### And the owner has a name
`ss -tnp` on the boxes attributes **194 of 194** on each, to a single PID:
| box | PID | process |
|---|---|---|
| `demo-felhom` | 2596329 | `/usr/local/bin/felhom-agent --config /etc/felhom-agent/agent.json` |
| `demo-hp` | 3199936 | `/usr/local/bin/felhom-agent --config /etc/felhom-agent/agent.json` |
**Zero are held by `pvestatd`. Zero by `proxmox-backup-client`.** Both agents have been running continuously
since 2026-08-12 (they did not restart); the count restarted at the proxy's 08-18 restart because that
restart closed the old sockets on both sides.
Each agent's own descriptor table is **208 fds, of which 196 are these connections** — so the leak is
bilateral. The agents' `RLIMIT_NOFILE` is 524287, so they are in no danger; that is a reason it stayed
invisible, not a reason it is harmless.
---
## The user-agent attribution (1.5) — the access log settles it independently
Over the same 46.18 h window, from ep0's own `access.log.1` + `access.log`:
| user agent | endpoint | requests | req/day | **descriptors leaked** |
|---|---|---|---|---|
| `libwww-perl/6.78` | `GET /admin/datastore` (pvestatd) | 81,192 | 42,195 | **0** |
| `proxmox-backup-client/1.0` | `GET …/felhom-offsite/status` | 80,061 | 41,607 | **0** |
| `libwww-perl/6.78` | `GET …/felhom-offsite/snapshots` | 1,131 | 588 | **0** |
| **`Go-http-client/1.1`** | **`GET …/felhom-offsite/snapshots`** | **387** | **201** | **388** |
| `Go-http-client/1.1` | `GET /version` | 371 | 193 | (same connections) |
| `Go-http-client/1.1` | `POST …/verify` + task status | 53 | 28 | (same connections) |
| | **total, both boxes** | **163,215** | **84,822** | **388** |
`Go-http-client/1.1` is `felhom-agent` — the same process `ss` names on the box side, reached by a completely
independent route. **387 agent `/snapshots` calls against 388 leaked sockets: one per call, within one.**
**162,404 requests from the two Proxmox pollers leaked nothing.** They are 99.5% of the traffic and 0% of the
leak.
### Cadence reconciliation — the numbers close
| source | cadence | cycles in 166,251 s |
|---|---|---|
| agent hub-report poll (`poll_seconds: 900`, read from each box's `agent.json`) | 15 min | 184.7 |
| `pbs.VerifyLoop` (`DefaultVerifyCadence = 6h`) | 6 h | 7.7 |
| | **sum** | **192.4** |
Observed leaked per box: **194**. Observed `POST …/verify` per box in the window: **8** (predicted 7.7).
Observed `GET /version` per box: ~185.5 (predicted 184.7). Mean interval between leaked descriptors per box:
**857 s**. Every count reconciles against a cadence read from configuration, not fitted to the data.
### Mechanism — named from source, and it is a two-line Go footgun
`felhom-agent/internal/pbs/client.go:56-60`:
```go
http: &http.Client{
Timeout: timeout,
Transport: &http.Transport{TLSClientConfig: tlsCfg},
},
```
A hand-rolled `http.Transport` takes the **zero value** for `IdleConnTimeout`, which in Go means *no limit* —
idle keep-alive connections are never closed. (`http.DefaultTransport` sets 90 s; a composite literal does
not inherit it.) That alone would be harmless if one client were reused. It is not:
`felhom-agent/cmd/felhom-agent/main.go:1486-1509` — `pbsTargetsFromPVE` — says so in its own doc comment:
> *"returns a `pbs.Targets` closure that, **each cycle**, discovers the pbs storages from the PVE config and
> **builds a fingerprint-pinned, token-authed client for each**"*
So each cycle constructs a **new** `Transport`, performs one request, and leaves the connection idle in that
transport's pool forever. The transport then becomes unreachable, but Go's `persistConn` read-loop goroutine
keeps the socket alive — an unreachable `http.Transport` does not close its connections. `grep` across the
whole `felhom-agent` repo for `CloseIdleConnections`, `IdleConnTimeout`, `MaxIdleConns`: **no matches at all.**
**The same composite-literal pattern appears in two more clients** — `internal/hub/client.go:53` and
`internal/proxmox/client.go:69`. Those are built once at start-up rather than per cycle, so they do not leak
by this route; they are recorded because the pattern is one refactor away from doing so. Filed as **R-344**.
---
## Control-window cleanliness (1.6)
The elapsed window is doing double duty as Phase C's control, so it has to be shown undisturbed. It was.
| check | finding |
|---|---|
| **ep0 host reboot** | none — booted 2026-08-03 11:12:57, up 17 d |
| **proxy / API daemon restart** | none — `NRestarts = 0` on both units, PID 551655 throughout |
| **box reboots** | none — both booted 2026-08-10 09:2xZ, up 10 d |
| **agent restarts** | none — both `ActiveEnterTimestamp` 2026-08-12 |
| **request-rate gaps** | **none.** Hourly totals across the window: 3,536–3,553 every hour, no hour missing |
| **HTTP errors** | **none.** Every response in the window is `200`, except 8 × `101` (expected protocol upgrades) |
| **tunnel flaps** | no evidence — WireGuard handshakes for `10.77.0.2`, `.3`, `.250` all seconds old; and a flap would have shown as a request gap or errors, and neither exists |
| **a backup inside the window?** | **NO.** The last offsite protocol upgrades were 2026-08-18 **03:57 and 03:58Z** — the incident re-runs, **before `t0` at 09:51:22Z**. Both boxes' `pvesm list felhom-pbs` confirms the newest snapshots are `2026-08-18T03:57:43Z` / `03:58:43Z`. The tier's `cadence_seconds` is **604800** (weekly), read from each box's `agent.json`, so the next offsite run is due ~2026-08-25 |
| **other non-poll activity** | **yes, and it is routine, quantified, and does not contaminate.** Server-side verify jobs ran on ep0 on a ~6 h cadence (8 per box in the window), and restore-test reads ran on 2026-08-19 at 04:45–04:50 and 06:52–06:54Z (8 reader upgrades total). Together with snapshot/version/task-status calls this is **~1,963 of 163,215 requests = 1.2%** of the window's traffic, and at most 8 of the 388 descriptors could be attributed to reader connections (≤2%). The verify cycle is already counted **inside** the 194/box reconciliation above — it is part of the measured leak, not a contaminant of it |
**Verdict: the control window is clean.** No correction is applied and none is needed.
**Two nuances recorded rather than smoothed over.**
1. `systemctl show proxmox-backup-proxy -p ActiveEnterTimestamp` reads **2026-08-18 03:54:54Z**, not 09:51:04Z,
while `NRestarts = 0` and `MainPID` did change. The upgrade therefore **re-exec'd** the proxy rather than
restarting the unit — systemd never saw a stop. Anyone using `ActiveEnterTimestamp` as the "when did this
proxy generation start" anchor would get a figure **5 h 56 m too early** and compute a rate ~12% low (388 fd over 52.1 h instead of 46.2 h = 178.7/day instead of 201.6/day).
Use `ps -o lstart= -p $MainPID`, as R-341's own command does.
2. ep0 carries a fourth WireGuard peer, `10.77.0.4`, whose last handshake was 2026-08-13 (7 d ago). It is
`drill-r50-0a4f9a`, a drill host, and its dormant peer entry is already recorded in
`architecture/_recovery-inventory-2026-07-28.md`. Outside the window; not a contaminant; not a new finding.
**Hub view.** No `pbsdr_box_unreachable` / `offsite_box_unreachable` and no `*_recovered` event was logged.
The positive observable rather than the absent one: the PBS-DR gauge refreshes on schedule
(`PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)`, every ~16 min through the run) and host reports land
from both boxes. **Honest limit:** the hub pod is 39 h old (redeployed for v0.106.0 at 2026-08-18 19:29), so
hub-side log evidence covers **36.6 of the window's 46.2 hours**. For the first 9.6 h the evidence is ep0's
own access log — which shows no gap and no error — and `NRestarts = 0`. Hub log timestamps render **CEST**.
---
## Q3 — is the leak rate proportional to the request rate?
### NOT ANSWERED BY MEASUREMENT. Phase C has not been run; it is held at STOP 1.
What exists instead is a **pre-registered prediction**, written and committed before any Phase C number can
exist: `evidence-ep0-established-connections-2026-08-20/phaseC-prediction.txt`. Its substance:
- Stopping `pvestatd` on `demo-hp` removes **both** pvestatd-driven streams from that box (the PVE PBS storage
plugin issues the `libwww-perl` datastore list *and* shells out to `proxmox-backup-client` for the status
call, both on pvestatd's cycle) — **−98.8% of demo-hp's requests, −49.4% of the fleet total**. If ep0's
request count does not fall by close to half, the independent variable did not move and no ratio may be
computed.
- **H1 (what Parts 1–2 predict): NOT proportional.** demo-hp's `felhom-agent` keeps running, so both boxes
keep leaking. Expect **~201.6 fd/day, unchanged — ~84 descriptors in a 10 h window (2σ 66–102) — split
symmetrically ~42/~42 between the two peers.**
- **H2 (the hypothesis Q3 was written to test): proportional.** Expect **~101 fd/day — ~42 descriptors in
10 h (2σ 29–55) — split strongly asymmetrically ~42/~0.**
H1 and H2 do not overlap at 2σ for a window of 10 h or more. The **peer split is the sharpest discriminator**
and it is free: it needs no second box and no arithmetic.
**A result matching H2 falsifies the Parts 1–2 attribution**, and the prediction file says so in those words,
so the outcome cannot be rationalised in either direction afterwards.
---
## Which fix the evidence points at
**No design here, per the spike-first gate — only the target.** The evidence points at
`felhom-agent/internal/pbs/client.go`'s HTTP transport lifetime, not at the poll rate. One `pbs.Client` is
constructed per cycle by `pbsTargetsFromPVE`, each carrying a fresh `http.Transport` whose `IdleConnTimeout`
is the zero value, and nothing ever closes it; the observed leak is exactly one socket per agent
`/snapshots` call, on both sides, on both boxes, and it reconciles with cadences read from configuration. A
fix that touches only the ~85,000/day Proxmox poll rate would reduce ep0's request load by ~99.5% and its
descriptor leak by **zero**. R-336's poll rate remains a genuine problem — 85,000 requests/day to a
weekly-write DR endpoint is still wrong — but **it is a different problem from this one, and the row's
"cut the poll rate, then confirm the fd count stops climbing" plan would have produced a confusing null
result.** That is the substantive change to R-336 this spike delivers.
---
## What was inconclusive
- **Q3 is unmeasured**, by design — Phase C is held at STOP 1 for the operator. Everything above about
proportionality is a prediction, labelled as one.
- **The ~9.6 h of hub-side evidence before the v0.106.0 pod redeploy is gone** with the previous pod's logs.
The window is covered by ep0-side evidence for that period, which is adequate for the questions asked, but
it is not the same evidence and is not presented as such.
- **Why `demo-hp`'s and `demo-felhom`'s leaked counts are *identical* rather than merely similar** is not
established. Both run the same cadences, so equality is expected — but exact equality at two separate
instants (194/194 and 196/196) is stronger than the cadences alone require, and no attempt was made to
explain it beyond noting it.
- **Whether a reader (restore-test) connection also leaks** was not separated out. At most 8 of 388 sockets
could be involved (≤2%), which is inside the noise, so it was not pursued.
@@ -0,0 +1,16 @@
=== part0-due-checks-gate.txt ===
captured: 2026-08-20T10:01:45+02:00 (DooPlex, CEST)
utc: 2026-08-20T08:01:45+00:00
repo HEAD: 848368ec38a7f9a49c6beb3a68b5620c822edc86
cmd: python3 scripts/due_checks_gate.py
--- stdout+stderr ---
DUE-CHECKS GATE FAILED: 1 dated check(s) are due or overdue as of 2026-08-20 (UTC).
R-341 due 2026-08-19 1 day(s) OVERDUE
measure: ep0 proxy fd count + ESTAB/CLOSE-WAIT split; PID must still be 551655
the command and its preconditions are in the R-341 row of documentation/backlog/OPEN-ITEMS.md
Take the measurement, record the result in that R-row, then remove the row from the
DUE-CHECKS block. Moving the date instead is allowed — state the reason in the R-row.
NOTE: this gate fires on a PUSH, not on the date; it may be later than the date.
rc=1
@@ -0,0 +1,141 @@
=== part0-repo-gates.txt ===
captured: 2026-08-20T08:01:52+00:00 UTC
cmd: python3 scripts/repo_gates.py
--- stdout+stderr ---
repo_gates (felhom.eu) — 10 gate(s)
==============================================================================
== gate: site (site_gates.py)
==============================================================================
site gates OK — BOM, emoji=0, nav/footer consistent, analytics present, no CDN, no legacy tokens, no <style>, cache-busted assets
==============================================================================
== gate: hostinstall (hostinstall_gates.py)
==============================================================================
ok: SCRIPT_VERSION=1.28.0
ok: header has no version literal
ok: hub carries no host-install version literal (241 .go/.html files scanned, 6 shapes checked)
ok: age is in the installed package set
ok: felhom-pbs-apply is fetched from the agent repo
ok: felhom-pbs-apply installed 0755 to /usr/local/sbin
ok: uninstall removes felhom-pbs-apply
ok: rendered agent.json defaults wg_tunnel.enabled=true
ok: byo assert no longer forbids wg_tunnel
ok: PVE_STORAGES default contains felhom-pbs
ok: no raw/branch/ ref in the installer — every run-time fetch is pinned
ok: fetch_raw pins the agent configs to the vouched agent version
ok: manifest: /scripts/ syncs from an installer tag
ok: manifest: the website still tracks main (a copy edit must not need a release)
ok: every arm that resolves the backup target also grants on it (2 resolution(s), 3 grant(s))
ok: the offsite tier arms no client-side prune (keep_last=0; retention is ep0's prune jobs)
hostinstall gates: ALL PASS
==============================================================================
== gate: hub-confirm (hub_confirm_gate.py)
==============================================================================
hub confirm gate OK — no native confirm()/prompt() in hub templates
==============================================================================
== gate: manifest-bearer (manifest_bearer_gate.py)
==============================================================================
manifests/felhom.secret.yaml:39 KNOWN-BACKLOG committed secret 65cee3c4...7a86 (secrets.md de-git backlog; not this gate's failure)
manifest bearer gate OK - no bearer-shaped literals in manifests/
==============================================================================
== gate: reuse-refs (reuse_refs_check.py /mnt/5_hdd/felhom.eu/git/felhom.eu)
==============================================================================
note [felhom.eu] line 75: api/handler.go (resolved by suffix → hub/internal/api/handler.go)
OK [felhom.eu]: 66 cited paths — exact 65, suffix 1, ambiguous 0, cross-repo 0, FAILED 0 (siblings searched: app-catalog-felhom.eu, felhom-agent, felhom-controller)
==============================================================================
== gate: instructions (instructions_gate.py /mnt/5_hdd/felhom.eu/git/felhom.eu)
==============================================================================
instructions_gate: /mnt/5_hdd/felhom.eu/git/felhom.eu
CLAUDE.md effective lines : 128 (ceiling 200)
version literals : 0
TEMPORARY blocks : 0
rule files : 4 (4 path-scoped)
workspace file : SYMLINK -> felhom.eu/documentation/runbooks/workspace-CLAUDE.md (resolves to the versioned copy)
memory index : 158 lines (ceiling 200), 20238 bytes (ceiling 25600)
memory index content : 33 version literal(s), 4 host address(es), 0 expired statement(s) [WARN only]
memory topic files : 125 indexed, 0 orphaned, 40 archived
register citations : 10 cited, 342 register items known
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:26: version literal '1.25.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [ISO train v1.25.0](iso-train-v1.25.0-2026-07-23.md) — R-71 build-gate (golden≥floor), r
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:47: version literal '1.2.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Offsite pool-box aggregate](offsite-pool-box-aggregate-2026-07-17.md) — R-5 hub 0.64/0.
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:50: version literal '0.90.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Guest RAM resize + fast-tick](guest-ram-resize-fasttick-2026-07-17.md) — R-24 controlle
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:50: version literal '0.143.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Guest RAM resize + fast-tick](guest-ram-resize-fasttick-2026-07-17.md) — R-24 controlle
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:59: version literal '0.142.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Offsite continuity](offsite-continuity-2026-07-17.md) — ctrl 0.142.0 orphan guard + hub
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:59: version literal '0.60.0' — the fleet is not uniform, so it is stale within a day. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Offsite continuity](offsite-continuity-2026-07-17.md) — ctrl 0.142.0 orphan guard + hub
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md: ... and 27 more version literal(s) — full list from the tally counts above.
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:42: host address '192.168.0.0' — operations/nodes.md is the single home for these. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Tailscale N100 location-independent](tailscale-n100-location-independent-2026-07-19.md)
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:46: host address '167.233.158.164' — operations/nodes.md is the single home for these. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Offsite PBS box RAM ceiling](offsite-pbs-box-ram-ceiling-2026-07-27.md) — **root SSH =
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:46: host address '10.77.0.1' — operations/nodes.md is the single home for these. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- [Offsite PBS box RAM ceiling](offsite-pbs-box-ram-ceiling-2026-07-27.md) — **root SSH =
WARNING: /mnt/5_hdd/felhom.eu/git/.claude-memory/MEMORY.md:139: host address '192.168.0.180' — operations/nodes.md is the single home for these. Not a failure: Claude writes this file between sessions, so this warning is aimed at the model that will next edit it, not at whoever is pushing.
- **CC runs ON DooPlex** (192.168.0.180) — repos `/mnt/5_hdd/felhom.eu/git/felhom-*`, buil
instructions_gate: OK (11 warning(s))
==============================================================================
== gate: golden-currency (golden_currency_gate.py)
==============================================================================
newest released controller : 0.216.0 (## v0.216.0 — one physical disk, one verdict (2026-08-14, R-335))
newest golden baked : 0.216.0 (documentation/tests/golden-0.216.0-2026-08-18)
golden currency gate OK — the newest released controller has a golden (NOTE: this checks the BAKE, not the vouch — see the module docstring)
==============================================================================
== gate: wire-contract (wire_contract_gate.py)
==============================================================================
wire-contract gate — 190 tag(s) checked across 4 declared wire(s); 80 skipped (generic / opaque / allowlisted)
wire-contract gate OK — every emitted field is at least decodable by its receiver
(BLIND SPOTS: generic tag names skipped; name-reachability is not use; only the
declared ROOTS are covered — hub desired-state and the agent local API are not.)
==============================================================================
== gate: hub-copy (hub_copy_gate.py)
==============================================================================
hub-copy gate OK — 95 hub file(s) scanned for 2 retired name(s); 4 customer surface(s) scanned for 4 retrieval stem(s), 0 registered claim(s), none unregistered
drift: controller gate's STEMS match the shared list (4 stem(s))
(BLIND SPOT: this checks the WORDS in the four declared customer surfaces. It cannot
tell whether a true-looking sentence is wired to a predicate that is actually true —
that is what render tests are for. And it does not read the operator's screens.)
==============================================================================
== gate: due-checks (due_checks_gate.py)
==============================================================================
DUE-CHECKS GATE FAILED: 1 dated check(s) are due or overdue as of 2026-08-20 (UTC).
R-341 due 2026-08-19 1 day(s) OVERDUE
measure: ep0 proxy fd count + ESTAB/CLOSE-WAIT split; PID must still be 551655
the command and its preconditions are in the R-341 row of documentation/backlog/OPEN-ITEMS.md
Take the measurement, record the result in that R-row, then remove the row from the
DUE-CHECKS block. Moving the date instead is allowed — state the reason in the R-row.
NOTE: this gate fires on a PUSH, not on the date; it may be later than the date.
==============================================================================
== summary
==============================================================================
site OK (exit 0)
hostinstall OK (exit 0)
hub-confirm OK (exit 0)
manifest-bearer OK (exit 0)
reuse-refs OK (exit 0)
instructions OK (exit 0)
golden-currency OK (exit 0)
wire-contract OK (exit 0)
hub-copy OK (exit 0)
due-checks FAILED (exit 1)
CONVICTED: due-checks
rc=1
@@ -0,0 +1,7 @@
=== Part 4 verification: due-checks gate AFTER clearing the 2026-08-19 row ===
captured: 2026-08-20T08:39:48+00:00 UTC
due-checks gate OK — 1 dated check(s) pending, none due yet.
today (UTC): 2026-08-20
nearest: R-341 due 2026-08-25 (in 5 day(s)) — same, +7 d. Anchor the elapsed time on `ps -o lstart= -p $MainPID`, NO
(fires on the next PUSH after a date passes, not on the date itself — by design)
rc=0
@@ -0,0 +1,33 @@
=== repo_gates.py — pre-push, AFTER Part 4 ===
captured: 2026-08-20T08:41:20+00:00 UTC
==============================================================================
hub-copy gate OK — 95 hub file(s) scanned for 2 retired name(s); 4 customer surface(s) scanned for 4 retrieval stem(s), 0 registered claim(s), none unregistered
drift: controller gate's STEMS match the shared list (4 stem(s))
(BLIND SPOT: this checks the WORDS in the four declared customer surfaces. It cannot
tell whether a true-looking sentence is wired to a predicate that is actually true —
that is what render tests are for. And it does not read the operator's screens.)
==============================================================================
== gate: due-checks (due_checks_gate.py)
==============================================================================
due-checks gate OK — 1 dated check(s) pending, none due yet.
today (UTC): 2026-08-20
nearest: R-341 due 2026-08-25 (in 5 day(s)) — same, +7 d. Anchor the elapsed time on `ps -o lstart= -p $MainPID`, NO
(fires on the next PUSH after a date passes, not on the date itself — by design)
==============================================================================
== summary
==============================================================================
site OK (exit 0)
hostinstall OK (exit 0)
hub-confirm OK (exit 0)
manifest-bearer OK (exit 0)
reuse-refs OK (exit 0)
instructions OK (exit 0)
golden-currency OK (exit 0)
wire-contract OK (exit 0)
hub-copy OK (exit 0)
due-checks OK (exit 0)
all felhom.eu gates OK
rc=0
@@ -0,0 +1,62 @@
PHASE C PREDICTION — written 2026-08-20 ~08:40Z, BEFORE any Phase C measurement exists.
Same discipline as evidence-ep0-pbs-upgrade-2026-08-18/stop1-ruling.txt: committed to git
before the mutation is performed, so the result cannot be rationalised afterwards.
-------------------------------------------------------------------------------
WHAT PARTS 1-2 ALREADY ESTABLISHED (measured, not assumed)
-------------------------------------------------------------------------------
Q2 outcome : (a) — both sides hold every connection. 194+194 = 388 = ep0 total,
and the 4 new sockets that appeared during the 31-min persistence
window carry the SAME source ports on ep0 and on the boxes.
Owner on the box side : felhom-agent, 100% (194/194 on each box, one PID each).
pvestatd and proxmox-backup-client hold ZERO.
Elapsed-window rate : 201.6 fd/day (388 fd over 166251 s), 2s = 181.2..222.1.
Request split : libwww-perl (pvestatd) 81192 req -> 0 descriptors leaked
proxmox-backup-client 80061 req -> 0 descriptors leaked
Go-http-client (agent) 811 req -> 388 descriptors leaked
(387 agent GET /snapshots calls vs 388 leaked sockets: 1:1 within 1)
-------------------------------------------------------------------------------
THE INDEPENDENT VARIABLE Phase C ACTUALLY MOVES
-------------------------------------------------------------------------------
Stopping pvestatd on demo-hp removes BOTH pvestatd-driven streams from that box (the PVE PBS
storage plugin issues the libwww-perl datastore list AND shells out to proxmox-backup-client
for the status call, both on pvestatd's cycle). Expected request effect:
demo-hp requests 81612 per 46.18 h -> ~982 per 46.18 h (-98.8%)
BOTH boxes, per day ~84822 -> ~42900 (-49.4%)
So the request rate roughly HALVES, as the spike intends. IF the ep0 request count does NOT
fall by close to half, the independent variable did not move and no ratio may be computed.
-------------------------------------------------------------------------------
PREDICTIONS, ONE PER HYPOTHESIS. For a 10-hour window (scale linearly for other lengths).
-------------------------------------------------------------------------------
H1 NOT PROPORTIONAL — the leak tracks the AGENT's cycle, not the request rate.
This is what Parts 1-2 predict, and it is the prediction this run commits to.
demo-hp's felhom-agent keeps running throughout, so both boxes keep leaking.
expected rate : ~201.6 fd/day, UNCHANGED
expected count : 84 descriptors in 10 h (2s band 66..102)
expected split : ~42 from 10.77.0.2 and ~42 from 10.77.0.3 — SYMMETRIC.
The symmetry is the sharpest single discriminator: under H1 the quietened box keeps
leaking at the same rate as the control box.
H2 PROPORTIONAL to total request rate (the hypothesis Q3 was written to test).
expected rate : ~101 fd/day
expected count : 42 descriptors in 10 h (2s band 29..55)
expected split : ~42 from 10.77.0.2, ~0 from 10.77.0.3 — STRONGLY ASYMMETRIC.
H1 and H2 do not overlap at 2 sigma for a window of 10 h or more. A 6-hour window gives
50 vs 25 (2s bands 36..64 vs 15..35) — separable but tighter; prefer the overnight run.
Under Q2 outcome (b) (half-open, ep0 only) the prediction would have been H2-like, and under
(c) Phase C would not have been run at all. Both are recorded here for completeness; the
measurement already excluded them.
-------------------------------------------------------------------------------
WHAT WOULD FALSIFY THE PARTS 1-2 ATTRIBUTION
-------------------------------------------------------------------------------
A result matching H2 — demo-hp's contribution going to ~zero while pvestatd is stopped — would
mean the socket ownership reading is not the whole story, and the attribution above must be
withdrawn rather than defended. Say so plainly if it happens.
@@ -0,0 +1,32 @@
ELAPSED-WINDOW SLOPE — proxy PID 551655, started 2026-08-18 09:51:04 UTC, NOT restarted since
(method identical to evidence-ep0-pbs-upgrade-2026-08-18/step2-slope-computation.txt)
t0 2026-08-18T09:51:22Z fd=17 (ESTAB 0)
tA 2026-08-20T08:02:13Z fd=405 (ESTAB 388, CLOSE-WAIT 0)
interval 166251 s = 46.181 h = 1.9242 d
delta 388 fd
= 8.40 fd/hour = 201.6 fd/DAY
Poisson uncertainty on n=388: sqrt(n)=19.7 counts
1 sigma on the rate: +/- 10.2/day -> 191.4 .. 211.9
2 sigma on the rate: +/- 20.5/day -> 181.2 .. 222.1
PRE-REGISTERED PREDICTION (spike prompt section 2, written before any number existed):
predicted leaked-descriptor count 370-450; confirm-band 330-490
at 183/day tightest before-figure -> expected 352 fd
at 200/day 5.6 h before-figure -> expected 385 fd
at 225/day 32-min after-figure -> expected 433 fd
OBSERVED: 388
VERDICT: IN RANGE (370-450). The rate is UNCHANGED since the 4.2.5-1 upgrade.
COMPOSITION — the split, not just the total:
fd0 17 with ESTAB 0 -> fdA 405 with ESTAB 388. 17+388 = 405 = fdA exactly.
CLOSE-WAIT is ABSENT from the ss histogram entirely (0), not merely flat.
=> 100% of the descriptor growth is ESTABLISHED connections on :8007.
RUNWAY to the 65536 soft limit from fd=405 at this rate:
323 days = 0.88 years (approx 2027-07-09)
BEFORE-figures for comparison (same measurement method, PID 542065 and 551655):
183/day (31 min window, 2026-08-18) 200/day (5.64 h window, 2026-08-18) 225/day (32 min, post-upgrade)
This window is 88x longer than the 31-min window and 97x its descriptor count.
@@ -0,0 +1,23 @@
=== ep0 reading A — 1.1 precondition + R-341 count ===
ep0 date: 2026-08-20T08:02:13+00:00 / UTC: 2026-08-20T08:02:13+00:00
epoch: 1787212933
PID=551655
--- proxy start (lstart) ---
Tue Aug 18 09:51:04 2026
--- proxy start (systemd ActiveEnterTimestamp) ---
Tue 2026-08-18 03:54:54 UTC
--- host uptime ---
up 2 weeks, 2 days, 20 hours, 49 minutes
boot: 2026-08-03 11:12:57
--- fd count ---
405
--- limits ---
Max open files 65536 65536 files
--- listener ---
State Recv-Q Send-Q Local Address:Port Peer Address:Port
LISTEN 0 1024 *:8007 *:*
--- socket state histogram (all states, sport 8007) ---
388 ESTAB
1 LISTEN
--- pbs version ---
proxmox-backup-server 4.2.5-1 running version: 4.2.5
@@ -0,0 +1,59 @@
=== 1.2 ownership — who is at the far end (reading A) ===
UTC: 2026-08-20T08:02:39+00:00 epoch=1787212959
--- peer address histogram (established, sport 8007) ---
194 [::ffff:10.77.0.3]
194 [::ffff:10.77.0.2]
--- with process ---
Recv-Q Send-Q Local Address:Port Peer Address:Port Process
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:37112 users:(("proxmox-backup-",pid=551655,fd=247))
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:40330 users:(("proxmox-backup-",pid=551655,fd=390))
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:38018 users:(("proxmox-backup-",pid=551655,fd=213))
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:56006 users:(("proxmox-backup-",pid=551655,fd=255))
--- full 4-tuple + timers (SAVED FOR DIFF) ---
389 /tmp/ep0-sockA.txt
--- sample (first 10) ---
Recv-Q Send-Q Local Address:Port Peer Address:Port Process
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:37112 users:(("proxmox-backup-",pid=551655,fd=247)) timer:(keepalive,1min13sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:40330 users:(("proxmox-backup-",pid=551655,fd=390)) timer:(keepalive,51sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:38018 users:(("proxmox-backup-",pid=551655,fd=213)) timer:(keepalive,30sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:56006 users:(("proxmox-backup-",pid=551655,fd=255)) timer:(keepalive,28sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:32844 users:(("proxmox-backup-",pid=551655,fd=136)) timer:(keepalive,12sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:58280 users:(("proxmox-backup-",pid=551655,fd=261)) timer:(keepalive,,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:33480 users:(("proxmox-backup-",pid=551655,fd=252)) timer:(keepalive,24sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:38610 users:(("proxmox-backup-",pid=551655,fd=96)) timer:(keepalive,18sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:55858 users:(("proxmox-backup-",pid=551655,fd=398)) timer:(keepalive,6.044sec,0)
0 0 [::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:37514 users:(("proxmox-backup-",pid=551655,fd=22)) timer:(keepalive,1min3sec,0)
--- idle-age distribution: parse timer(keepalive,<age>) ---
19 timer:(keepalive,30sec,
19 timer:(keepalive,18sec,
18 timer:(keepalive,38sec,
18 timer:(keepalive,14sec,
16 timer:(keepalive,26sec,
16 timer:(keepalive,22sec,
16 timer:(keepalive,10sec,
13 timer:(keepalive,34sec,
12 timer:(keepalive,1min13sec,
11 timer:(keepalive,42sec,
10 timer:(keepalive,59sec,
10 timer:(keepalive,16sec,
10 timer:(keepalive,1.980sec,
9 timer:(keepalive,6.080sec,
9 timer:(keepalive,55sec,
9 timer:(keepalive,47sec,
9 timer:(keepalive,32sec,
9 timer:(keepalive,24sec,
9 timer:(keepalive,1min5sec,
9 timer:(keepalive,1min3sec,
--- wireguard peers ---
wg0 KNaFXHiY9l08UhPO4gxUBFQz2WF3RYWyUGL8k+hzDVo= 37.191.56.193:43407
yNVpWt9Ekid9p459/VLHbmCDHIi8xTUYHbgazUp5S00= 37.191.56.193:62827
sJzw0h9w8IIeM9/BG/a1xetxEDGJQEUFMSXP2EQpyDk= 37.191.56.193:52231
kdhOHMyADRpaTaFmh8ypwsWngvBpIyMyon80DJK+00M= 37.191.56.193:46129
wg0 KNaFXHiY9l08UhPO4gxUBFQz2WF3RYWyUGL8k+hzDVo= 1787212855
wg0 yNVpWt9Ekid9p459/VLHbmCDHIi8xTUYHbgazUp5S00= 1787212952
wg0 sJzw0h9w8IIeM9/BG/a1xetxEDGJQEUFMSXP2EQpyDk= 1787212944
wg0 kdhOHMyADRpaTaFmh8ypwsWngvBpIyMyon80DJK+00M= 1786601749
@@ -0,0 +1,46 @@
=== 1.3 descriptor type breakdown (Proxmox support's own diagnostic) ===
UTC: 2026-08-20T08:02:59+00:00
PID=551655
--- lsof TYPE histogram ---
390 IPv6
32 REG
7 unix
3 a_inode
2 DIR
1 CHR
--- lsof TCP count ---
390
--- /proc fd link-target class histogram (independent of lsof) ---
397 socket
2 anon_inode:[eventpoll]
1 anon_inode:[eventfd]
1 0
1 /var/log/proxmox-backup/api/auth.log
1 /var/log/proxmox-backup/api/access.log
1 /var/lib/proxmox-backup/rrdb/rrd.journal
1 /mnt/pbs-datastore/.lock
1 /dev/null
=== 1.6 control-window cleanliness ===
--- access log files ---
total 55744
drwxr-xr-x 2 backup backup 4096 Aug 20 00:00 .
drwxr-xr-x 4 root root 4096 Jul 3 19:33 ..
-rw-r--r-- 1 backup backup 4023740 Aug 20 08:02 access.log
-rw-r--r-- 1 backup backup 43115482 Aug 19 23:59 access.log.1
-rw-r--r-- 1 backup backup 700249 Jul 24 00:00 access.log.10.zst
-rw-r--r-- 1 backup backup 724750 Jul 19 00:00 access.log.11.zst
-rw-r--r-- 1 backup backup 612227 Jul 15 00:00 access.log.12.zst
-rw-r--r-- 1 backup backup 959113 Aug 20 00:00 access.log.2.zst
-rw-r--r-- 1 backup backup 975898 Aug 16 00:00 access.log.3.zst
-rw-r--r-- 1 backup backup 1274332 Aug 13 00:00 access.log.4.zst
-rw-r--r-- 1 backup backup 1078875 Aug 9 00:00 access.log.5.zst
-rw-r--r-- 1 backup backup 850578 Aug 6 00:00 access.log.6.zst
-rw-r--r-- 1 backup backup 857058 Aug 3 00:00 access.log.7.zst
-rw-r--r-- 1 backup backup 986392 Jul 31 00:00 access.log.8.zst
-rw-r--r-- 1 backup backup 705209 Jul 28 00:00 access.log.9.zst
-rw-r--r-- 1 backup backup 164293 Aug 18 03:55 auth.log
--- log format sample ---
::ffff:10.77.0.3 - felhom@pbs!demo-hp [20/08/2026:08:02:52 +0000] "GET /api2/json/admin/datastore/felhom-offsite/status" 200 67 proxmox-backup-client/1.0
::ffff:10.77.0.3 - felhom@pbs!demo-hp [20/08/2026:08:02:54 +0000] "GET /api2/json/admin/datastore" 200 110 libwww-perl/6.78
::ffff:10.77.0.3 - felhom@pbs!demo-hp [20/08/2026:08:02:54 +0000] "GET /api2/json/admin/datastore/felhom-offsite/status" 200 67 proxmox-backup-client/1.0
@@ -0,0 +1,31 @@
=== ep0 reading B (1.4 persistence) ===
UTC: 2026-08-20T08:33:42+00:00 epoch=1787214822
PID=551655 (precondition: must still be 551655)
fd count: 409
State Recv-Q Send-Q Local Address:Port Peer Address:Port
LISTEN 0 1024 *:8007 *:*
--- state histogram ---
392 ESTAB
1 LISTEN
--- peer histogram ---
196 10.77.0.2
196 10.77.0.3
=== 1.4 DIFF of full 4-tuples between reading A and reading B ===
sockets in reading A : 388
sockets in reading B : 392
in BOTH (long-lived = LEAK) : 388
only in A (closed since) : 0
only in B (opened since = new): 4
--- the 'only in A' set (did ANY socket close?) ---
--- the 'only in B' set (new arrivals in the interval) ---
[::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:45620
[::ffff:10.77.0.1]:8007 [::ffff:10.77.0.2]:53226
[::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:37554
[::ffff:10.77.0.1]:8007 [::ffff:10.77.0.3]:46214
--- keepalive-timer distribution over the LONG-LIVED set (reading B) ---
392 timer:(keepalive)
--- retransmit counter across ALL sockets (0 = peer is answering keepalives) ---
392 retrans=0
@@ -0,0 +1,113 @@
=== date range per log file ===
--- access.log ---
20/08/2026:00:00:04 +0000
20/08/2026:08:03:25 +0000
--- access.log.1 ---
16/08/2026:00:00:00 +0000
19/08/2026:23:59:56 +0000
--- access.log.2.zst ---
13/08/2026:00:00:04 +0000
16/08/2026:00:00:00 +0000
--- access.log.3.zst ---
09/08/2026:00:00:00 +0000
12/08/2026:23:59:58 +0000
=== 1.5 ATTRIBUTION — who makes the requests, by source IP + token + user agent ===
--- window slice: 18/08 from 09:51 onward, 19/08 all, 20/08 to now ---
5 10.77.0.3 [18/08/2026:12:52:31 libwww-perl/6.78
5 10.77.0.3 [16/08/2026:18:52:31 libwww-perl/6.78
5 10.77.0.3 [16/08/2026:12:52:31 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:08:02:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:07:52:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:07:47:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:07:42:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:06:32:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:05:27:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:05:22:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:05:17:09 libwww-perl/6.78
5 10.77.0.2 [20/08/2026:04:12:09 libwww-perl/6.78
5 10.77.0.2 [18/08/2026:03:54:55 libwww-perl/6.78
5 10.77.0.2 [15/08/2026:22:34:57 libwww-perl/6.78
5 10.77.0.2 [15/08/2026:12:54:56 libwww-perl/6.78
5 10.77.0.2 [15/08/2026:09:29:56 libwww-perl/6.78
5 10.77.0.2 [15/08/2026:08:04:56 libwww-perl/6.78
5 10.77.0.2 [14/08/2026:23:04:56 libwww-perl/6.78
5 10.77.0.2 [14/08/2026:19:24:56 libwww-perl/6.78
5 10.77.0.2 [14/08/2026:18:29:56 libwww-perl/6.78
=== request TOTALS in the elapsed window (18/08 09:51Z -> now) ===
3538 17/08/2026 13
3538 17/08/2026 14
3538 17/08/2026 15
3548 17/08/2026 16
3538 17/08/2026 17
673 17/08/2026 18
335 18/08/2026 03
3546 18/08/2026 04
3538 18/08/2026 05
3546 18/08/2026 06
3536 18/08/2026 07
3538 18/08/2026 08
3546 18/08/2026 09
3550 18/08/2026 10
3546 18/08/2026 11
3543 18/08/2026 12
3540 18/08/2026 13
3540 18/08/2026 14
3540 18/08/2026 15
3548 18/08/2026 16
3540 18/08/2026 17
3551 18/08/2026 18
3540 18/08/2026 19
3540 18/08/2026 20
3540 18/08/2026 21
3550 18/08/2026 22
3540 18/08/2026 23
3550 19/08/2026 00
3540 19/08/2026 01
3540 19/08/2026 02
3540 19/08/2026 03
3553 19/08/2026 04
3540 19/08/2026 05
3552 19/08/2026 06
3540 19/08/2026 07
3540 19/08/2026 08
3540 19/08/2026 09
3546 19/08/2026 10
3540 19/08/2026 11
3546 19/08/2026 12
3540 19/08/2026 13
3540 19/08/2026 14
3540 19/08/2026 15
3548 19/08/2026 16
3540 19/08/2026 17
3548 19/08/2026 18
3540 19/08/2026 19
3540 19/08/2026 20
3540 19/08/2026 21
3548 19/08/2026 22
3540 19/08/2026 23
3548 20/08/2026 00
3540 20/08/2026 01
3540 20/08/2026 02
3540 20/08/2026 03
3546 20/08/2026 04
3540 20/08/2026 05
3546 20/08/2026 06
3539 20/08/2026 07
209 20/08/2026 08
=== 1.6 BACKUP ACTIVITY in the window — protocol upgrades / writes ===
28 "POST /api2/json/admin/datastore/felhom-offsite/verify" 200 139
28 "POST /api2/json/admin/datastore/felhom-offsite/verify" 200 131
4 "GET //api2/json/reader?backup-id=9201&backup-time=1787025523&backup-type=ct&debug=true&ns=demo-hp&store=felhom-offsite" 101 0
4 "GET //api2/json/reader?backup-id=9201&backup-time=1787025463&backup-type=ct&debug=true&ns=demo-felhom&store=felhom-offsite" 101 0
4 "GET //api2/json/reader?backup-id=9201&backup-time=1786476553&backup-type=ct&debug=true&ns=demo-hp&store=felhom-offsite" 101 0
1 "PUT /api2/json/admin/datastore/felhom-offsite/notes?backup-id=9201&backup-time=1787025523&backup-type=ct&notes=felhom+local-api&ns=demo-hp" 200 13
1 "PUT /api2/json/admin/datastore/felhom-offsite/notes?backup-id=9201&backup-time=1787025463&backup-type=ct&notes=felhom+local-api&ns=demo-felhom" 200 13
1 "POST /api2/json/admin/datastore/felhom-offsite/upload-backup-log?backup-id=9201&backup-time=1787025523&backup-type=ct&ns=demo-hp" 200 13
1 "POST /api2/json/admin/datastore/felhom-offsite/upload-backup-log?backup-id=9201&backup-time=1787025463&backup-type=ct&ns=demo-felhom" 200 13
1 "GET //api2/json/backup?backup-id=9201&backup-time=1787025523&backup-type=ct&benchmark=false&debug=true&ns=demo-hp&store=felhom-offsite" 101 0
1 "GET //api2/json/backup?backup-id=9201&backup-time=1787025463&backup-type=ct&benchmark=false&debug=true&ns=demo-felhom&store=felhom-offsite" 101 0
--- explicit: any line mentioning backup/upload/chunk/finish ---
2
@@ -0,0 +1,34 @@
ATTRIBUTION — who makes the requests, and who leaks the descriptors
window 2026-08-18 ~09:51Z -> 2026-08-20 08:03Z (166251 s = 46.18 h)
user agent endpoint requests req/day
libwww-perl/6.78 pvestatd: GET /admin/datastore 81192 42195
proxmox-backup-client/1.0 GET .../felhom-offsite/status 80061 41607
libwww-perl/6.78 GET .../felhom-offsite/snapshots 1131 588
Go-http-client/1.1 GET .../felhom-offsite/snapshots 387 201
Go-http-client/1.1 GET /version 371 193
Go-http-client/1.1 POST .../verify + task status 53 28
TOTAL (both boxes, all agents) 163215 84822
LEAKED DESCRIPTORS OVER THE SAME WINDOW: 388 (all ESTABLISHED on :8007)
requests by libwww-perl + proxmox-backup-client : 162404 descriptors leaked: 0
requests by Go-http-client/1.1 (felhom-agent) : 811 descriptors leaked: 388
Go-http-client GET .../snapshots calls : 387
leaked ESTAB sockets : 388 -> ratio 1.0026 (ONE per call, within 1)
Per box, at the instant of reading A:
ep0 ESTAB from 10.77.0.2 (demo-felhom) = 194 ; from 10.77.0.3 (demo-hp) = 194
demo-felhom ESTAB to 10.77.0.1:8007 = 194 ; demo-hp = 194
194 + 194 = 388 = ep0 total. Both sides agree EXACTLY -> Q2 outcome (a).
CADENCE RECONCILIATION (why 194 and not 185):
hub report poll poll_seconds=900 -> 184.7 cycles in the window
pbs VerifyLoop DefaultVerifyCadence=6h -> 7.7 cycles in the window
sum -> 192.4 observed leaked/box: 194
observed POST .../verify per box in the window: 8 (matches 7.7)
observed GET /version per box: ~185.5 (matches the 184.7 hub cycles)
Mean interval between leaked descriptors, per box:
857 s = 14.28 min (900 s poll + a 6 h verify cycle superposed)
@@ -0,0 +1,69 @@
=== 1.5 ATTRIBUTION (clean) — source IP + token + endpoint + user agent ===
window: 18/08 09:51Z -> 20/08 08:0xZ, from access.log.1 + access.log
40598 10.77.0.3 felhom@pbs!demo-hp /api2/json/admin/datastore" 200 libwww-perl/6.78
40594 10.77.0.2 felhom@pbs!demo-felhom /api2/json/admin/datastore" 200 libwww-perl/6.78
40032 10.77.0.3 felhom@pbs!demo-hp /api2/json/admin/datastore/felhom-offsite/status" 200 proxmox-backup-client/1.0
40029 10.77.0.2 felhom@pbs!demo-felhom /api2/json/admin/datastore/felhom-offsite/status" 200 proxmox-backup-client/1.0
566 10.77.0.3 felhom@pbs!demo-hp /api2/json/admin/datastore/felhom-offsite/snapshots libwww-perl/6.78
565 10.77.0.2 felhom@pbs!demo-felhom /api2/json/admin/datastore/felhom-offsite/snapshots libwww-perl/6.78
194 10.77.0.2 felhom@pbs!demo-felhom /api2/json/admin/datastore/felhom-offsite/snapshots Go-http-client/1.1
193 10.77.0.3 felhom@pbs!demo-hp /api2/json/admin/datastore/felhom-offsite/snapshots Go-http-client/1.1
186 10.77.0.2 felhom@pbs!demo-felhom /api2/json/version" 200 Go-http-client/1.1
185 10.77.0.3 felhom@pbs!demo-hp /api2/json/version" 200 Go-http-client/1.1
8 10.77.0.3 felhom@pbs!demo-hp /api2/json/admin/datastore/felhom-offsite/verify" 200 Go-http-client/1.1
8 10.77.0.2 felhom@pbs!demo-felhom /api2/json/admin/datastore/felhom-offsite/verify" 200 Go-http-client/1.1
5 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000003:6A84A9FD:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
5 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000001:6A84559D:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
4 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000006:6A84FE5D:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
4 10.77.0.3 felhom@pbs!demo-hp //api2/json/reader proxmox-backup-client/1.0
4 10.77.0.2 felhom@pbs!demo-felhom /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:0000000C:6A8534EF:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dfelhom:felhom@pbs%21demo-felhom:/status" 200 Go-http-client/1.1
4 10.77.0.2 felhom@pbs!demo-felhom /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000004:6A84E08F:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dfelhom:felhom@pbs%21demo-felhom:/status" 200 Go-http-client/1.1
4 10.77.0.2 felhom@pbs!demo-felhom /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000000:6A8437CF:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dfelhom:felhom@pbs%21demo-felhom:/status" 200 Go-http-client/1.1
4 10.77.0.2 felhom@pbs!demo-felhom //api2/json/reader proxmox-backup-client/1.0
3 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000011:6A8552BD:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
2 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:0000001D:6A86A43D:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
2 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000019:6A864FDD:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
2 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000016:6A85FB7D:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
2 10.77.0.3 felhom@pbs!demo-hp /api2/json/nodes/felhom-hetzner/tasks/UPID:felhom-hetzner:00086AE7:07B20B30:00000014:6A85A71D:verify:felhom%5Cx2doffsite%5Cx3ans-demo%5Cx2dhp:felhom@pbs%21demo-hp:/status" 200 Go-http-client/1.1
=== per-box request totals in that same window ===
81603 10.77.0.2
81612 10.77.0.3
=== which token belongs to which IP ===
10.77.0.2 felhom@pbs!demo-felhom
10.77.0.3 felhom@pbs!demo-hp
=== 1.6 verify-job timestamps (are they inside the window?) ===
1 17/08/2026:12:52:45 +0000
1 17/08/2026:16:45:35 +0000
1 18/08/2026:04:45:35 +0000
1 18/08/2026:06:52:45 +0000
1 18/08/2026:10:45:35 +0000
1 18/08/2026:12:52:45 +0000
1 18/08/2026:16:45:35 +0000
1 18/08/2026:18:52:45 +0000
1 18/08/2026:22:45:35 +0000
1 19/08/2026:00:52:45 +0000
1 19/08/2026:04:45:35 +0000
1 19/08/2026:06:52:45 +0000
1 19/08/2026:10:45:35 +0000
1 19/08/2026:12:52:45 +0000
1 19/08/2026:16:45:35 +0000
1 19/08/2026:18:52:45 +0000
1 19/08/2026:22:45:35 +0000
1 20/08/2026:00:52:45 +0000
1 20/08/2026:04:45:35 +0000
1 20/08/2026:06:52:45 +0000
=== 1.6 reader / backup protocol upgrades with timestamps ===
1 18/08/2026 03:57
1 18/08/2026 03:58
3 19/08/2026 04:45
1 19/08/2026 04:50
3 19/08/2026 06:52
1 19/08/2026 06:54
=== 1.6 any HTTP error (non-2xx) in the window ===
8 101
163207 200
@@ -0,0 +1,31 @@
=== 1.6 window cleanliness — reboots / restarts / flaps ===
--- box uptimes + agent + pvestatd ---
[felhom-pve]
hostname: demo-felhom
boot: 2026-08-10 09:25:35
uptime: up 1 week, 3 days, 1 hour, 8 minutes
wg handshake: f3d1ZI7/2/r+FWz8eo8Wl2HVygTZK9wBIN2M3dNHsgA= 1787214780
wg transfer: wg-felhom f3d1ZI7/2/r+FWz8eo8Wl2HVygTZK9wBIN2M3dNHsgA= 6720170264 3106980548
[demo-hp]
hostname: felhom-host
boot: 2026-08-10 09:28:18
uptime: up 1 week, 3 days, 1 hour, 6 minutes
wg handshake: f3d1ZI7/2/r+FWz8eo8Wl2HVygTZK9wBIN2M3dNHsgA= 1787214869
wg transfer: wg-felhom f3d1ZI7/2/r+FWz8eo8Wl2HVygTZK9wBIN2M3dNHsgA= 8576925788 3139271384
--- ep0 host/daemon restart evidence ---
boot: 2026-08-03 11:12:57
proxy ActiveEnter: Tue 2026-08-18 03:54:54 UTC
proxy NRestarts: 0
api NRestarts: 0
wg peers + allowed-ips:
wg0 KNaFXHiY9l08UhPO4gxUBFQz2WF3RYWyUGL8k+hzDVo= 10.77.0.2/32
wg0 yNVpWt9Ekid9p459/VLHbmCDHIi8xTUYHbgazUp5S00= 10.77.0.250/32
wg0 sJzw0h9w8IIeM9/BG/a1xetxEDGJQEUFMSXP2EQpyDk= 10.77.0.3/32
wg0 kdhOHMyADRpaTaFmh8ypwsWngvBpIyMyon80DJK+00M= 10.77.0.4/32
wg handshakes (epoch):
wg0 KNaFXHiY9l08UhPO4gxUBFQz2WF3RYWyUGL8k+hzDVo= 1787214780
wg0 yNVpWt9Ekid9p459/VLHbmCDHIi8xTUYHbgazUp5S00= 1787214829
wg0 sJzw0h9w8IIeM9/BG/a1xetxEDGJQEUFMSXP2EQpyDk= 1787214869
wg0 kdhOHMyADRpaTaFmh8ypwsWngvBpIyMyon80DJK+00M= 1786601749
now epoch: 1787214870
@@ -0,0 +1,7 @@
=== locate hub pod ===
felhom-system contact-mailer-5bb869b85b-pqtjt 1/1 Running 0 52d
felhom-system felhom-webpage-7969454965-gcv5n 3/3 Running 226 (6d3h ago) 7d2h
felhom-system filebrowser-59ff87cd88-662kz 1/1 Running 0 70d
felhom-system hub-654bbc8fbc-9wld9 1/1 Running 0 39h
felhom-system umami-7cd7f95cd8-89wrn 1/1 Running 1 (70d ago) 74d
felhom-system umami-db-5fd98f59c5-xhwfr 1/1 Running 0 70d
@@ -0,0 +1,25 @@
=== hub pod: hub-654bbc8fbc-9wld9 (felhom-system), age 39h, restarts 0 ===
NOTE: pod is 39h old, so it covers 08-19 ~17:30Z onward only; the window starts 08-18 09:51Z.
--- reachability / unreachable / recovered events in pod log ---
2026/08/18 19:29:07 [INFO] Offsite pool-box checker initialized: box=611714 fill warn=80% crit=90%, oversub warn=2.00x, unreachable after 3 consecutive failed reads, refresh 15m0s
2026/08/18 19:29:07 [INFO] PBS-DR box checker initialized: fill warn=80% crit=90%, unreachable after 3 consecutive failed reads, refresh 15m0s
(empty above = no unreachable/recovered event logged)
--- PBS-DR / offsite gauge lines (positive observable) ---
2026/08/20 09:34:31 [INFO] PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)
2026/08/20 09:46:32 [INFO] Offsite pool-box refreshed: 0.2% full (2.4 GB of 1.00 TB), Σ shared quota 150 GB, oversub 0.15x
2026/08/20 09:50:30 [INFO] PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)
2026/08/20 10:02:31 [INFO] Offsite pool-box refreshed: 0.2% full (2.4 GB of 1.00 TB), Σ shared quota 150 GB, oversub 0.15x
2026/08/20 10:06:31 [INFO] PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)
2026/08/20 10:17:31 [INFO] Offsite pool-box refreshed: 0.2% full (2.4 GB of 1.00 TB), Σ shared quota 150 GB, oversub 0.15x
2026/08/20 10:22:31 [INFO] PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)
2026/08/20 10:32:32 [INFO] Offsite pool-box refreshed: 0.2% full (2.4 GB of 1.00 TB), Σ shared quota 150 GB, oversub 0.15x
--- host reports from the two boxes (last few) ---
2026/08/20 10:22:35 [INFO] host-report from demo-hp-bb76ea (1 guests, 5 storage targets, 2 backups, 2 restore-tests, 2 pbs-snapshots, 14944 bytes)
2026/08/20 10:22:35 [INFO] DR-recipe host-half stored for customer demo-hp (host demo-hp-bb76ea, v1)
2026/08/20 10:30:33 [INFO] host-report from demo-felhom-8363b5 (1 guests, 4 storage targets, 2 backups, 2 restore-tests, 2 pbs-snapshots, 14340 bytes)
2026/08/20 10:30:33 [INFO] DR-recipe host-half stored for customer demo-felhom (host demo-felhom-8363b5, v1)
2026/08/20 10:31:34 [INFO] DR-recipe app-half stored for customer demo-hp (v1)
2026/08/20 10:31:34 [INFO] Received report from demo-hp (3145 bytes)
@@ -0,0 +1,42 @@
##################### felhom-pve #####################
host: demo-felhom date: 2026-08-20T10:04:37+02:00 UTC: 2026-08-20T08:04:37+00:00 epoch=1787213077
--- state histogram, dport 8007 ---
194 ESTAB
--- total established to 8007 ---
194
--- WHICH PROCESS holds them (histogram) ---
194 users:(("felhom-agent"
--- per-PID ---
194 pid=2596329
--- name the PIDs ---
pid=2596329 felhom-agent /usr/local/bin/felhom-agent --config /etc/felhom-agent/agent.json
--- sample 5 with timers ---
Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
0 0 10.77.0.2:32844 10.77.0.1:8007 users:(("felhom-agent",pid=2596329,fd=69)) timer:(keepalive,5.776sec,0)
0 0 10.77.0.2:32894 10.77.0.1:8007 users:(("felhom-agent",pid=2596329,fd=197)) timer:(keepalive,3.216sec,0)
0 0 10.77.0.2:33098 10.77.0.1:8007 users:(("felhom-agent",pid=2596329,fd=190)) timer:(keepalive,3.728sec,0)
0 0 10.77.0.2:33108 10.77.0.1:8007 users:(("felhom-agent",pid=2596329,fd=194)) timer:(keepalive,8.336sec,0)
0 0 10.77.0.2:33256 10.77.0.1:8007 users:(("felhom-agent",pid=2596329,fd=139)) timer:(keepalive,1.680sec,0)
--- save full for diff ---
195 /tmp/box-sockA.txt
##################### demo-hp #####################
host: felhom-host date: 2026-08-20T10:04:38+02:00 UTC: 2026-08-20T08:04:38+00:00 epoch=1787213078
--- state histogram, dport 8007 ---
194 ESTAB
--- total established to 8007 ---
194
--- WHICH PROCESS holds them (histogram) ---
194 users:(("felhom-agent"
--- per-PID ---
194 pid=3199936
--- name the PIDs ---
pid=3199936 felhom-agent /usr/local/bin/felhom-agent --config /etc/felhom-agent/agent.json
--- sample 5 with timers ---
Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
0 0 10.77.0.3:32980 10.77.0.1:8007 users:(("felhom-agent",pid=3199936,fd=106)) timer:(keepalive,12sec,0)
0 0 10.77.0.3:33490 10.77.0.1:8007 users:(("felhom-agent",pid=3199936,fd=61)) timer:(keepalive,4.018sec,0)
0 0 10.77.0.3:34054 10.77.0.1:8007 users:(("felhom-agent",pid=3199936,fd=70)) timer:(keepalive,433ms,0)
0 0 10.77.0.3:34174 10.77.0.1:8007 users:(("felhom-agent",pid=3199936,fd=140)) timer:(keepalive,12sec,0)
0 0 10.77.0.3:34348 10.77.0.1:8007 users:(("felhom-agent",pid=3199936,fd=20)) timer:(keepalive,8.113sec,0)
--- save full for diff ---
195 /tmp/box-sockA.txt
@@ -0,0 +1,54 @@
##################### felhom-pve #####################
host: demo-felhom UTC: 2026-08-20T08:34:01+00:00 epoch=1787214841
--- state histogram, dport 8007 ---
196 ESTAB
--- owner ---
196 users:(("felhom-agent"
--- persistence diff A vs B (source port is the key) ---
A=194 B=196 both=194 closed=0 new=2
closed set:
new set:
10.77.0.2:45620
10.77.0.2:53226
--- agent uptime (has it restarted? if so the count would have reset) ---
Wed 2026-08-12 18:45:28 CEST
2596329
--- agent fd total ---
agent fds: 208
Max open files 524287 524288 files
--- pvestatd state (Part 3 precondition) ---
active
1215
--- backup schedule: next offsite run? ---
"target_id": "felhom-pbs" "cadence_seconds": 604800 "keep_last": 0
--- last PBS snapshots on this box (pvesm) ---
Volid Format Type Size VMID
felhom-pbs:backup/ct/9201/2026-08-11T04:54:07Z pbs-ct backup 3978122771 9201
felhom-pbs:backup/ct/9201/2026-08-18T03:57:43Z pbs-ct backup 4104429602 9201
##################### demo-hp #####################
host: felhom-host UTC: 2026-08-20T08:34:02+00:00 epoch=1787214842
--- state histogram, dport 8007 ---
196 ESTAB
--- owner ---
196 users:(("felhom-agent"
--- persistence diff A vs B (source port is the key) ---
A=194 B=196 both=194 closed=0 new=2
closed set:
new set:
10.77.0.3:37554
10.77.0.3:46214
--- agent uptime (has it restarted? if so the count would have reset) ---
Wed 2026-08-12 20:52:29 CEST
3199936
--- agent fd total ---
agent fds: 208
Max open files 524287 524288 files
--- pvestatd state (Part 3 precondition) ---
active
1298
--- backup schedule: next offsite run? ---
"target_id": "felhom-pbs" "cadence_seconds": 604800 "keep_last": 0
--- last PBS snapshots on this box (pvesm) ---
Volid Format Type Size VMID
felhom-pbs:backup/ct/9201/2026-08-11T19:29:13Z pbs-ct backup 4067039591 9201
felhom-pbs:backup/ct/9201/2026-08-18T03:58:43Z pbs-ct backup 4287958060 9201
File diff suppressed because one or more lines are too long