felhom.eu/documentation/audits/INCIDENT-ep0-pbs-fd-exhaustion-2026-08-18.md

INCIDENT — ep0's PBS proxy ran out of file descriptors, 2026-08-18

Detected by: the two whole_guest_backup_failed alert mails (04:30 and 04:32 CEST). Resolved: 05:52 CEST (proxy restart) / 05:59 CEST (both re-run backups landed). Offsite DR unavailable: 2026-08-17 20:15 CEST → 2026-08-18 05:52 CEST, ≈ 9 h 37 m. Data lost: none. Backups missed: none — the weekly offsite run was re-driven the same morning. Evidence: evidence-ep0-fd-2026-08-18/ (pre-restart and post-fix state, access-log tail).

What the operator saw

Two mails, both severity: error, one per box:

time (CEST)	customer	event	tier
04:30	demo-felhom	whole_guest_backup_failed	felhom-pbs
04:32	demo-hp	whole_guest_backup_failed	felhom-pbs

Both carried the same underlying error:

could not activate storage 'felhom-pbs': felhom-pbs: error fetching datastores
  - 500 Can't connect to 10.77.0.1:8007 (Connection timed out)

Two customers, two hosts, one error — so the fault was never on the customer boxes. It was on the single thing they share: ep0, the Hetzner offsite PBS endpoint at 10.77.0.1 over wg-felhom.

What it was NOT

Ruled out before touching anything, because each of these is the obvious suspect for a timeout and each was innocent:

• Not the tunnel. WireGuard was up on both boxes with handshakes seconds old; ep0's wg show listed both peers live. ICMP to 10.77.0.1 answered in ~33 ms from felhom-pve.
• Not the firewall. ep0's inet filter input chain carries tcp dport 8007 iifname "wg0" accept and it was in force.
• Not a dead daemon. proxmox-backup-proxy was active (running), and ss -lntp showed it holding the listening socket on *:8007.
• Not disk. /mnt/pbs-datastore was 3.4 G used of 98 G; no D-state processes; no I/O errors.
• Not a stale binary. proxmox-backup-manager version prints available then running, and it read proxmox-backup-server 4.2.5-1 running version: 4.2.2. That 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 is merely available in the repo, and the proxy binary on disk is dated 2026-06-18, matching 4.2.2. Restarting the daemons did not (and could not) change that string.

Root cause — accept() returning EMFILE

The proxy was listening and never accepting. Three numbers say it:

ss -lnt '( sport = :8007 )'   →  LISTEN  Recv-Q 1025  Send-Q 1024   *:8007
ls /proc/<proxy>/fd | wc -l   →  1024
grep 'open files' /proc/<proxy>/limits  →  soft 1024 / hard 524288

Send-Q on a listening socket is the accept backlog; Recv-Q is how many completed connections are waiting in it. At 1025 the queue had overflowed a 1024-deep backlog. The process held exactly 1024 file descriptors — its soft RLIMIT_NOFILE. Every accept() was failing with EMFILE, so connections completed their handshake, queued, and timed out. The daemon looked healthy from the outside and served nobody.

It was wedged from its own loopback too — curl https://127.0.0.1:8007/ on ep0 timed out. That is the observation that moves this from "a network problem" to "a process problem", and it is worth reaching for early: a listener that cannot serve 127.0.0.1 has no network left to blame.

Why the descriptors ran out

Of the 1024 fds, 1016 were sockets, and 547 connections sat in CLOSE-WAIT with unread data (Recv-Q 1543). CLOSE-WAIT means the peer closed and the local application never called close() — accumulated, unreleased connections. That is a leak, and it was fed by an unreasonable request volume:

• ~85,000 requests/day, a flat 3,538/hour — a request roughly every second, all day.
• 74,445 GET /api2/json/admin/datastore (libwww-perl — PVE's pvestatd)
• 73,171 GET /api2/json/admin/datastore/felhom-offsite/status (proxmox-backup-client)
• everything else — snapshots, version, verify — is under 2,000 combined.

Fourteen days of that (ep0 last booted 2026-08-03) walked the fd count to the 1024 ceiling. The last request the proxy ever served was 2026-08-17 18:15:32 UTC. The scattered HTTP 400s that begin at 17:34 UTC are the exhaustion setting in, not its cause.

So it is a three-part failure, and all three parts have to be named: a leak in the proxy's connection handling, a poll rate high enough to make that leak reach a limit in a fortnight, and a soft limit of 1024 that no drop-in had ever raised.

The fix

1. LimitNOFILE=65536 drop-ins for proxmox-backup-proxy.service and proxmox-backup.service (/etc/systemd/system/<unit>.d/20-nofile.conf), each carrying the reason in a comment. The API daemon held only 15 fds and was not implicated — its limit was raised for symmetry, and the drop-in says so, so a later reader does not mistake it for a second culprit.
2. Restarted both daemons. Verified after: soft limit 65536, fd count back to 18, Recv-Q 0, curl https://127.0.0.1:8007/ → 200.
3. Verified from the customer side, not just from ep0 — from both boxes, https://10.77.0.1:8007/ returned 200 in ~0.1 s and pvesm status showed felhom-pbs pbs active.
4. Re-drove the missed backups through the product path, not vzdump by hand: POST /backup?target=felhom-pbs on each agent's local API, called from inside the guest's controller container with the controller's own credentials — the same call the scheduler makes.

Result

box	snapshot	size	duration
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

The hub agrees, which is the check that actually closes this. A snapshot on ep0 proves the write landed; it does not prove the fleet's own picture recovered. Both boxes' next host reports carry felhom-pbs success=true — demo-felhom at 04:00:33Z, demo-hp at 04:07:35Z — so the operator view is green on the same evidence, not on a restart having been performed.

Both snapshot directories carry a full manifest on ep0 (index.json.blob, root.pxar.didx, catalog.pcat1.didx, client.log.blob, pct.conf.blob) — not a partial upload. Both hosts' own /var/log/pve/tasks/index records the re-run vzdump as OK.

The daily local tier was never affected. felhom-backup (dir) completed on both boxes this morning — 05:00:17 on demo-felhom (1.49 GB), 05:02:00 on demo-hp (1.48 GB). The offsite PBS tier is weekly (cadence_seconds: 604800 vs 86400 for local), and its previous snapshots were 2026-08-11. Today was the first weekly run to fall inside the outage window — which is why a 9½-hour outage cost exactly one attempt and no coverage.

Findings filed

• R-336 — the offsite endpoint is polled ~1 request/second. 85k requests/day from two boxes to a DR endpoint is what converts a slow fd leak into a fortnightly outage. Two pollers duplicate the same question (admin/datastore and felhom-offsite/status) at roughly the same rate.

• R-337 — /backup/status trailed the completed backup by minutes on demo-hp, then caught up. The re-run landed on ep0 at 03:58:43Z with the host's task index reading OK, yet the controller's status endpoint was still serving the 03:27:00Z failure at ~04:03Z; demo-felhom reflected its new result within ~40 s. It cleared without intervention — demo-hp's 04:07:35Z host report carries felhom-pbs success=true. Filed as WATCHING, not as a defect, and the distinction is the point: during the recovery this looked like a second failure, and it was not one. See the note below.

• R-338 — demo-hp is not on the R-50 island at all, and operations/nodes.md says it is. nodes.md records both boxes as island-migrated on 2026-07-25 (local_api on 169.254.253.1:8443/vmbr9, guest eth1 169.254.253.2/30). That is true of felhom-pve and false of demo-hp, side by side in their own agent.json:

  	felhom-pve	demo-hp
  listen_addr	169.254.253.1:8443	192.168.0.87:8443 (the LAN address)
  island_bridge / island_guest_addr	present	absent — the keys do not exist
  guest 9201 NICs	net0 vmbr0 + net1 vmbr9	net0 only
  vmbr9	carries the guest veth	exists, zero members

  The controller's controller.yaml points at 192.168.0.87:8443, so the product works — this is drift in the inventory, not a broken box. But it has two costs. A session that trusts the page addresses the wrong endpoint (this one did, read the resulting timeout as a fault, and spent a step on it). And more substantially, the agent's local API is bound to the customer LAN on this box rather than to a point-to-point island — which is the exposure R-50 existed to remove. Either migrate demo-hp or correct the page; leaving both as they are keeps a documented security property that one of the two fleet boxes does not have.

• PBS 4.2.5-1 is available and 4.2.2-1 is installed. Not applied — upgrading a production offsite endpoint was outside the scope authorised here. Worth checking its changelog for the connection- handling leak before deciding.

What to watch

The drop-in raises the ceiling; it does not fix the leak. At the observed rate the old limit was reached in 14 days, so 65536 buys roughly 2.5 years at the same slope — but the slope is the defect. The positive observable is the fd count itself, not the absence of an alert:

ssh root@<ep0> 'PID=$(systemctl show proxmox-backup-proxy -p MainPID --value); \
  ls /proc/$PID/fd | wc -l; ss -lnt "( sport = :8007 )"'

A healthy proxy sits near 20 fds with Recv-Q 0. A rising fd count between restarts confirms the leak is still live — an unchanging one after a poll-rate reduction would confirm the fix.

It is still live, and it was measured rather than assumed. At 16 m 43 s after the restart the proxy held 19 fds (from 18) with 1 connection in CLOSE-WAIT.

⚠ CORRECTED 2026-08-18 09:50 UTC — the two numbers first published here were wrong

This section originally read "one descriptor per ~17 minutes is ≈ 85/day … it puts the next ceiling at roughly 2 years". Both figures are wrong, and the reason is worth keeping: they were extrapolated from a single 17-minute window whose delta was one descriptor. A sample of one cannot carry a daily rate, and the agreement with the historical ~73/day that made it feel solid was coincidence.

Re-measured on the same proxy generation (PID 542065, unrestarted) during RUNBOOK ep0 PBS upgrade, two independent windows:

window	from	to	rate
31 min	09:18:21Z fd=62	09:49:46Z fd=66	183/day
5.64 h	04:11:36Z fd=19	09:49:46Z fd=66	200/day

The real rate is ~185–200/day — about 2.6× what was published — and the runway to the 65536 ceiling is ~357 days, not two years. Still an enormous improvement on the fortnight the old limit gave, but under a year, so it is a deadline rather than a comfort.

And the mechanism named above is the minority one. Across that window CLOSE-WAIT held flat at 1 while ESTAB grew 45 → 49: all the growth was established connections. At the wedge the split was 1011 ESTAB / 543 CLOSE-WAIT, so ESTAB was the larger half there too and this document put its emphasis on the wrong one. R-336's fix must target connections the proxy never reaps, not only sockets left in CLOSE-WAIT.

The leak is unfixed; only its period changed.

---

Follow-up — 2026-08-18, later the same morning: the PBS upgrade

Run under RUNBOOK — ep0: read the PBS changelog, then decide whether to upgrade. Two supervised STOPs, both cleared by the operator. Evidence: evidence-ep0-pbs-upgrade-2026-08-18/.

The changelog said nothing relevant — and that was the finding

The runbook's first job was a pure read: does anything between the installed 4.2.2-1 and the candidate 4.2.5-1 fix connection handling? All three intervening entries were read in full (128 lines) and swept for connection|file descriptor|fd|accept(|close_wait|keep-alive|socket|EMFILE| nofile|leak|proxy|listen|backlog|hyper|tokio.

Exactly one keyword hit, and it is a false positive:

* S3: config: allow editing the use-node-config flag that controls whether requests S3 endpoints honor the node's proxy settings or not

That is HTTP-proxy configuration for S3 requests, not the proxmox-backup-proxy daemon. What the range actually contains: 4.2.5-1 is a security release hardening client-supplied backup manifests (an archive name in a crafted manifest could make a sync job read or write outside the snapshot directory as the backup user; manifests are now held in memory and only persisted at backup finish with per-archive checksum verification), plus a sync/push chunk-reuse fix. 4.2.4-1 is S3 rate limits, a file-locking user-lookup cache, docs. 4.2.3-1 is UI/journal work, an LDAP search-filter escape, tape and timezone fixes.

Nothing addresses descriptor lifetime or connection reaping. The recommendation was therefore do not upgrade for this reason.

What was done anyway, and why that is fine

Operator ruling at STOP 1: upgrade regardless, for rehearsal value — "see how that works for us, we need practice with that too". So this was executed as a practice run of the upgrade procedure on a Tier-2 protected machine, not as a fix for the leak, and the distinction was written into stop1-ruling.txt before any numbers existed, precisely so the outcome could not be rationalised afterwards in either direction.

STOP 2 cleared with Hetzner snapshot 421440873 felhom-hetzner-20260818, 15.06 GB, status Available. That snapshot covers /dev/sda only. /mnt/pbs-datastore is /dev/sdb, a separate 100 GB Volume, and Hetzner server snapshots exclude attached volumes — so it is a rollback for the software state and not a backup of the backup data. Acceptable here because a package install writes no datastore content; it must not be remembered as datastore protection.

Result

apt-get install --only-upgrade proxmox-backup-server, 09:51:00→09:51:06Z, exit 0. A -s simulation was run first and reported 0 to remove, so the runbook's abort condition never triggered. Upgraded server/client/docs to 4.2.5-1, plus one genuinely new dependency, proxmox-enterprise-support- keyring 1.1 — which the 4.2.4-1 changelog had declared, a small but real consistency check between what was read and what apt did.

check	result
installed (dpkg -l)	server / client / docs 4.2.5-1
daemons	proxmox-backup-proxy active running, proxmox-backup active running
proxy restarted	PID 542065 → 551655 @ 09:51:04
effective open files	65536 / 65536 — the drop-in survived the new package
Recv-Q	0
loopback	200 in 12 ms
from felhom-pve	200 in 0.103 s, felhom-pbs active
from demo-hp	200 in 0.096 s, felhom-pbs active
hub gauge, post-upgrade	11:59:31 [INFO] PBS-DR box refreshed: 3.7% full (3.7 GB of 97.9 GB)

proxmox-backup-manager version now reads 4.2.5-1 running version: 4.2.5. This independently settles the confusion recorded in the original incident: the string was never reporting a stale daemon, and now that installed and running genuinely match, both halves agree.

One false alarm, mine: systemctl is-active proxmox-backup-api returned inactive. That unit does not exist — systemctl cat says "No files found for proxmox-backup-api.service". The real pair is proxmox-backup-proxy.service ("API Proxy Server") and proxmox-backup.service ("API Server"), both active. A bad query, not a fault, and it is written down because it looked exactly like a fault for as long as it took to check.

The slope: unchanged, as predicted

	window	delta	rate
before (PID 542065)	09:18:21Z fd=62 → 09:49:46Z fd=66	+4 / 1885 s	183/day
after (PID 551655)	09:51:22Z fd=17 → 10:23:21Z fd=22	+5 / 1919 s	225/day

These are not distinguishable. The two windows differ by a single descriptor; Poisson uncertainty on n=4 is ±2 and on n=5 is ±2.2, so both are consistent with one unchanged underlying rate. The after-figure being numerically higher is noise, not a regression — and emphatically not an improvement. This is the expected outcome and it matches the changelog: no mechanism, no change.

Composition after the upgrade repeats the pattern that matters: ESTAB 0 → 5, CLOSE-WAIT 0 → 1.

Thirty minutes cannot settle this, in either direction, and this document does not claim it does. The honest checks are +24 h (2026-08-19 ~10:00Z) and +7 d (2026-08-25 ~10:00Z) against the new t0 of fd=17 at 09:51:22Z, PID 551655 — filed as R-341.

What this run did not do

Did not reduce the poll rate (R-336 stays open — an upgrade that fixed the leak still would not make ~85,000 requests/day to a weekly-write DR endpoint correct), did not touch the LimitNOFILE drop-ins, did not run full-upgrade or touch the kernel, did not trigger a backup/restore/verify to "prove" the endpoint, and did not change anything on either customer box. Nothing was provisioned, so there is nothing to tear down; no .deb was downloaded, as apt-get changelog served the text directly.