admin
172584c26f
gates / gates (push) Failing after 14s
Checklist item "confirm your own push's CI run by run ID". Run 348,
head_sha ebfd0967c, conclusion failure, elapsed 13 s -- the inherited
golden-currency conviction (R-334), not a new fault: CI's only step is the
same repo_gates.py --fast entry point, and 13 s is the honest-failure band
rather than R-265's reap band.
Stated plainly that the run LOG could not be read (runs/348/logs and
tasks/348/logs both 404 authenticated as admin, runs/348/jobs empty, web
endpoint 302), so naming the gate is an inference from the local run plus
gates.yml -- not CI's own words. Standing rule 2: a "no access" claim names
what was tried.
Also notes the [felhom CI] gates FAILED mail run 348 will send, so it is not
read as a second incident alongside this morning's backup alerts.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_016p1PTCzb8rF5G9Aa1qhpBN
134 lines
8.2 KiB
Markdown
134 lines
8.2 KiB
Markdown
# REPORT — a listening socket that served nobody (2026-08-18, early)
|
|
|
|
**Trigger:** two `whole_guest_backup_failed` alert mails, 04:30 and 04:32 CEST.
|
|
**Outcome:** root cause found on **ep0**, fixed, both missed backups re-driven and landed.
|
|
**No repo code changed** — this was an operational run. Documentation, register and evidence only.
|
|
|
|
---
|
|
|
|
## 1. What was wrong
|
|
|
|
Both alerts were the same incident and neither was on a customer box. `demo-felhom` and `demo-hp`
|
|
each failed their `felhom-pbs` tier with `Can't connect to 10.77.0.1:8007 (Connection timed out)` —
|
|
the one thing they share, the Hetzner offsite PBS endpoint.
|
|
|
|
On ep0, `proxmox-backup-proxy` was `active`, held its listening socket, and **served nobody**:
|
|
|
|
```
|
|
ss -lnt '( sport = :8007 )' → LISTEN Recv-Q 1025 Send-Q 1024
|
|
ls /proc/<proxy>/fd | wc -l → 1024 # == its soft RLIMIT_NOFILE
|
|
```
|
|
|
|
`Send-Q` on a listener is the accept backlog; `Recv-Q` is the queue depth. At 1025 against 1024 the
|
|
queue had overflowed, because `accept()` was returning `EMFILE` on every call. **1016 of the 1024
|
|
descriptors were sockets and 547 connections sat in `CLOSE-WAIT`** — a connection leak, fed by
|
|
~85,000 requests/day, that reached the ceiling after 14 days of uptime. Last request served:
|
|
2026-08-17 18:15:32 UTC. Offsite DR was therefore down **≈ 9 h 37 m**.
|
|
|
|
**The observation that settled it:** the daemon was wedged from its own loopback too —
|
|
`curl https://127.0.0.1:8007/` on ep0 timed out. A listener that cannot serve `127.0.0.1` has no
|
|
network left to blame, and that check is cheap enough to make early.
|
|
|
|
Full record, including everything that was ruled out first (tunnel, nftables, disk, dead daemon):
|
|
**`documentation/audits/INCIDENT-ep0-pbs-fd-exhaustion-2026-08-18.md`**.
|
|
|
|
## 2. What was done
|
|
|
|
1. `LimitNOFILE=65536` drop-ins for `proxmox-backup-proxy.service` and `proxmox-backup.service`, each
|
|
carrying its reason inline. **The API daemon was not implicated** (15 fds) and its drop-in says so
|
|
— a later reader must not mistake it for a second culprit.
|
|
2. Restarted both. After: soft limit 65536, fds back to 18, `Recv-Q 0`, loopback `200`.
|
|
3. **Verified from the customer side, not only from ep0** — both boxes got `200` in ~0.1 s and
|
|
`pvesm status` read `felhom-pbs pbs active`.
|
|
4. Re-drove the missed backups **through the product path** — `POST /backup?target=felhom-pbs` on
|
|
each agent's local API, issued from inside the guest's controller container with the controller's
|
|
own credentials, i.e. the same call the scheduler makes. Not a hand-run `vzdump`.
|
|
|
|
**Result:** `demo-felhom` → `ct/9201/2026-08-18T03:57:43Z` (4.10 GB, 36.4 s);
|
|
`demo-hp` → `ct/9201/2026-08-18T03:58:43Z` (4.29 GB, 41.5 s). Both directories carry a full manifest
|
|
on ep0, and both hosts log the re-run vzdump as `OK`. **And the hub agrees** — both boxes' next host
|
|
reports carry `felhom-pbs success=true` (04:00:33Z and 04:07:35Z), so the operator view went green on
|
|
the evidence rather than on the fact that a restart was performed.
|
|
**No data was lost and no backup was skipped** — the daily local
|
|
tier was never affected (it completed on both boxes at 05:00 and 05:02), and the PBS tier is weekly,
|
|
so the outage window cost exactly one attempt, which was re-driven the same morning.
|
|
|
|
Evidence copied off ep0 **before** the restart, per standing rule 5:
|
|
`documentation/audits/evidence-ep0-fd-2026-08-18/` — pre-restart state, post-fix state, access-log tail.
|
|
|
|
## 3. What I got wrong, and corrected
|
|
|
|
- **`proxmox-backup-manager version` prints *available* then *running*.** It read
|
|
`4.2.5-1 running version: 4.2.2`, which looks exactly like a daemon left behind by a package
|
|
upgrade. It is not: `dpkg -l` shows **4.2.2-1 installed**, 4.2.5-1 merely available in the repo,
|
|
and the on-disk binary is dated 2026-06-18. I restarted the API daemon on that mistaken reading;
|
|
harmless, and its drop-in is a genuine improvement, but it was not needed.
|
|
- **I addressed `demo-hp`'s agent at the island address** because `operations/nodes.md` says that box
|
|
is island-migrated. It is not (**R-338**), and the resulting timeout was briefly read as a fault.
|
|
|
|
## 4. Findings filed — R-336, R-337, R-338
|
|
|
|
All three are in `documentation/backlog/OPEN-ITEMS.md` with numbers, per the registers-first rule.
|
|
|
|
- **R-336 — the poll rate is the real defect.** ~1 request/second against a DR endpoint written to
|
|
weekly. `LimitNOFILE` raises the ceiling; **it does not fix the leak**, it converts a fortnightly
|
|
outage into a multi-year one.
|
|
- **R-337 — a status endpoint that trailed its own artifact, then caught up. WATCHING, not a defect.**
|
|
`demo-hp`'s `/backup/status` was still serving the superseded 03:27:00Z failure at ~04:03Z while the
|
|
snapshot sat on ep0 and the host logged `OK`; `demo-felhom` updated within ~40 s. **I filed this as
|
|
a defect and that was premature** — the next host report (04:07:35Z) carried the success and the
|
|
skew cleared with no intervention. Rewritten as WATCHING, with the explicit instruction not to open
|
|
a fix until someone establishes whether this is just collection cadence. Recorded at all because
|
|
during the recovery it read as a second failure, and it was not one.
|
|
- **R-338 — `demo-hp` is not on the R-50 island and `nodes.md` says it is.** No `island_bridge` keys,
|
|
guest has no `eth1`, `vmbr9` has zero members, and the agent's local API is bound to the customer
|
|
LAN — the exposure R-50 existed to remove.
|
|
|
|
**Not done, deliberately:** PBS 4.2.5-1 was not applied. Upgrading a production offsite endpoint was
|
|
outside what this run was authorised to do, and its changelog should be read for the connection-
|
|
handling leak first.
|
|
|
|
## 5. Gates — one pre-existing conviction, and a stated bypass
|
|
|
|
`python3 scripts/repo_gates.py --fast` → **rc=1, CONVICTED: golden-currency.** Eight of nine gates
|
|
pass. The conviction is **R-334, inherited and not caused here**: newest released controller
|
|
**0.216.0**, newest golden bake **0.214.0**, so a new install misses two releases. The gate reads
|
|
`felhom-controller/CHANGELOG.md` and `documentation/tests/golden-*` — **this session touched
|
|
neither**, and its whole diff is documentation. Baking is possible; **vouching is
|
|
operator-password-gated, and a baked-but-unvouched golden is worse than none**, so it is not a
|
|
one-sided job CC can finish.
|
|
|
|
**This push therefore used `git push --no-verify`, stated here per `.claude/rules/gates.md`.**
|
|
R-334 is updated in the register with the new numbers rather than left reading 0.215.0.
|
|
|
|
**CI checked by run ID, as the checklist requires: run `348`, `head_sha ebfd0967c`, conclusion
|
|
`failure`, elapsed 13 s** (04:09:45→04:09:58Z). Expected and inherited — CI's only step is
|
|
`python3 scripts/repo_gates.py --fast`, the same entry point that convicts golden-currency locally,
|
|
with the sibling repos fetched. The 13 s runtime places it in the workflow's own "honest gate
|
|
failure" band rather than the R-265 reap band, so the result is the gate speaking, not the runner.
|
|
**I could not read the run log to name the gate from CI's own mouth** — `actions/runs/348/logs` and
|
|
`actions/tasks/348/logs` both 404, `actions/runs/348/jobs` returns an empty list, authenticated as
|
|
`admin`, and the web log endpoint 302s. So this is an inference from the local run plus the workflow
|
|
definition, not a direct reading, and it is stated as such.
|
|
|
|
**Expect one `[felhom CI] gates FAILED in admin/felhom.eu` mail for run 348** — the workflow alarms
|
|
on failure by design. It is this push, and it is the golden-currency row, not a new fault; the same
|
|
mails on 12 and 14 August have the same cause.
|
|
|
|
*(Noted for accuracy: the first gate run was piped to `tail`, which returned `rc=0` — `tail`'s exit
|
|
code, not the gate's. It was re-run unpiped to read the real `rc=1`. That is standing rule 1's trap
|
|
in its smaller form, and the number reported above is the unpiped one.)*
|
|
|
|
## 6. What to watch
|
|
|
|
The positive observable is the descriptor count, not the absence of an alert — an empty alert queue
|
|
is equally consistent with "healthy" and "wedged again":
|
|
|
|
```bash
|
|
ssh root@<ep0> 'PID=$(systemctl show proxmox-backup-proxy -p MainPID --value); \
|
|
ls /proc/$PID/fd | wc -l; ss -lnt "( sport = :8007 )"'
|
|
```
|
|
|
|
Healthy is ~20 fds and `Recv-Q 0`. **A count climbing between restarts means R-336's leak is still
|
|
live.**
|