From 831794e98c3b91e393e6f6587da34bd28845e399 Mon Sep 17 00:00:00 2001 From: dtoro Date: Fri, 3 Jul 2026 22:04:43 +0200 Subject: [PATCH] docs(rclone): root-cause the "stalls" as OOM, not Proton; bump RAM to 2G The recurring silent-freeze incidents on LXC 132 were rclone-rcd.service getting OOM-killed under the original 1 GiB allocation, not a protondrive backend quirk as first suspected. journalctl confirmed the OOM kill at the exact freeze point. Bumped LXC memory to 2 GiB (live, no reboot) and the full folder set (cloud/documents/repos) completed cleanly afterward. Also documents two watchdog bugs found while chasing this: a wrong stats-group key that made a healthy sync look falsely frozen, and a blocking systemctl restart that caused the watchdog to silently disable itself after firing once. Both fixed; watchdog kept as a safety net. --- containers/132-rclone.md | 74 +++++++++++++++++++++++----------------- 1 file changed, 43 insertions(+), 31 deletions(-) diff --git a/containers/132-rclone.md b/containers/132-rclone.md index bf58753..800adda 100644 --- a/containers/132-rclone.md +++ b/containers/132-rclone.md @@ -13,7 +13,8 @@ so this landed on **132**.) - **IP:** `192.168.8.214` (static, set in PVE `net0` config — same pattern as grimmory/authentik) - **Privilege:** privileged (root in-container = host root → reads every `/mnt/library` subtree, incl. `homecloud/` and `documents/`, regardless of owner) -- **Resources:** 1 core / 1 GiB RAM / 8 GiB rootfs (Debian 13) +- **Resources:** 1 core / 2 GiB RAM / 8 GiB rootfs (Debian 13) — bumped from 1 GiB on 2026-07-03 + after `rclone-rcd.service` was OOM-killed under real load (see "Known issue" below) - **Mounts:** `/mnt/library` **read-only** (`mp0: /mnt/library,mp=/mnt/library,ro=1`) — a backup job must never be able to write into the library - **Public hostname:** none — the UI is **LAN-only, no auth** (by design) @@ -97,31 +98,41 @@ gotcha](../infrastructure/media-permissions.md#gotchas) — worth adding to [agent-enrollment.md troubleshooting](../operations/agent-enrollment.md#troubleshooting) if it recurs on future LXC bootstraps. -## Known issue: silent protondrive stalls + watchdog +## Known issue: `rclone-rcd.service` OOM-killed under 1 GiB RAM (root cause, resolved) -The protondrive backend has been observed (twice in the first 24h) to hang a transfer at 100% (or -mid-percentage) with **zero bytes, zero errors, zero retries** for hours — no timeout ever fires, -including `--timeout 5m`/`--contimeout 30s` set via the rc `_config` (confirmed applied via -`options/get`, made no difference). Signature: `core/stats` `transferring` list shows the exact same -byte counts across repeated polls; `journalctl -u rclone-rcd.service` goes completely silent (no -new lines at all) once it happens. The only reliable fix found is **killing and restarting** -(`systemctl restart rclone-backup.service`) — rclone sync is idempotent on resume, so already- -uploaded bytes aren't re-transferred. +What looked like repeated "protondrive silently stalls" was actually **`rclone-rcd.service` (the rc +API daemon backing the Web GUI and, since the rc-API redesign, all actual sync work) getting +OOM-killed** under the original 1 GiB RAM allocation — `journalctl` confirms +`A process of this unit has been killed by the OOM killer` at the exact moment a transfer had +"frozen." systemd's own `Restart=on-failure` (5s) auto-respawns it, but every in-flight job's state +is lost on the kill, which looked identical to a silent backend hang from the outside (frozen +`core/stats`, no new log lines). **Fix: bumped the LXC's memory to 2 GiB** (`pct set 132 -memory +2048` — applies live via the host cgroup, confirmed via `cat /sys/fs/cgroup/lxc/132/memory.max` on +hubris, no container reboot needed). After the bump, the full folder set (`cloud` 287G, `documents` +249M, `repos` 83M) completed cleanly with no further kills. **`rclone-backup-watchdog.timer`** (every 5 min) → `rclone-backup-watchdog.sh`: if `rclone-backup.service` is active but total transferred bytes (global `core/stats` on the rc API) -haven't moved for 15 minutes, it restarts the service automatically. State kept in -`/var/lib/rclone-backup/watchdog-state.json`, cleared whenever the service isn't running so a stale -timestamp doesn't cause a false trigger next time it starts. +haven't moved for 15 minutes, it restarts both `rclone-rcd.service` (clears any stuck/orphaned job — +this is the actual daemon holding the work, not the thin wrapper) and then `rclone-backup.service` +(`--no-block`, load-bearing — see below). Kept as a safety net even after the RAM fix, in case +memory pressure returns under a larger folder set later. State kept in +`/var/lib/rclone-backup/watchdog-state.json`, cleared whenever the service isn't running. -**Runner monitoring bug (fixed 2026-07-03):** the runner's per-job progress polling queried -`core/stats` under group key `job/`, but rclone actually tracks stats under whatever `_group` -name the job was submitted with. This silently returned all-zero stats the entire time, making a -perfectly healthy sync look stalled at 0 bytes for 22+ hours in the per-run log — the real progress -was only visible via `core/stats` with no group filter (global) or a `job/list`+`job/status` cross- -check. Fixed by using the same `group` variable throughout. **Lesson: distrust the per-run log's -"progress bytes=" line at a glance during this incident window; cross-check with unfiltered -`core/stats` before concluding a stall is real.** +**Two watchdog design bugs found and fixed while chasing this (2026-07-03):** +1. **Wrong stats-group key.** Per-job progress polling queried `core/stats` under `job/`, + but rclone tracks stats under whatever `_group` name the job was submitted with. Made a perfectly + healthy sync look stalled at 0 bytes for 22+ hours in its own log. Fixed by using the same + `group` variable consistently. **Lesson: distrust the per-run log's "progress bytes=" line during + an incident; cross-check with unfiltered `core/stats` first.** +2. **Watchdog restarted only the thin wrapper, and blocked doing it.** The actual `rclone sync` work + runs inside `rclone-rcd.service`, not `rclone-backup.service` — restarting the wrapper alone left + any stuck job orphaned inside `rcd` while a new wrapper submitted a duplicate job on top. Worse, + `systemctl restart rclone-backup.service` (no `--no-block`) blocks until the *new* invocation's + long-running `ExecStart` exits — which could be hours — so the watchdog's own oneshot service + never logged "Finished," and `OnUnitActiveSec` (which schedules relative to the previous run + *finishing*) never fired again. The watchdog silently disabled itself after exactly one use. + Fixed: restart `rclone-rcd.service` first, then `rclone-backup.service` with `--no-block`. ## Related @@ -132,17 +143,18 @@ check. Fixed by using the same `group` variable throughout. **Lesson: distrust t ## Changelog -### 2026-07-03 — two silent protondrive stalls hit; watchdog added; monitoring bug fixed +### 2026-07-03 — root cause found (OOM, not Proton); RAM bumped to 2 GiB; full folder set completed -The `cloud` sync stalled silently twice in its first ~24h (see "Known issue" above) — once -pre-timeout-fix (~6.5h with zero progress before being caught), once post-fix (~22h, but that -second one turned out to be **partly a false alarm**: a bug in the runner's stats-group key made a -healthy, actively-transferring sync (real progress 48.6G → 62.4G confirmed via unfiltered -`core/stats`) look completely frozen in its own log. Fixed the group-key bug, then caught and -confirmed a **second, genuine** stall (zero rcd log activity for 15+ min, frozen byte counts) and -restarted again. Added `rclone-backup-watchdog.timer`/`.service` (5-min interval, 15-min stall -threshold) so future stalls auto-recover without manual intervention. Total transferred as of this -entry: ~62.4 GB of the ~145 GB selected set. +What looked like repeated silent "protondrive stalls" turned out to be **`rclone-rcd.service` +getting OOM-killed** under the original 1 GiB RAM allocation — confirmed via +`journalctl -u rclone-rcd.service` showing `killed by the OOM killer` at the exact freeze point. +Bumped the LXC to 2 GiB RAM (live, no reboot). After the bump: `cloud` (287G) completed cleanly +(exit 0), `documents` (249M) completed with 1 minor error (259.7 MB transferred), `repos` (83M) +completing as of this entry. Also fixed two real watchdog bugs found while chasing this (wrong +stats-group key making a healthy sync look frozen; watchdog restarting only the wrapper with a +blocking `systemctl restart`, causing it to silently disable itself after one use) — see "Known +issue" above for full detail. The watchdog is kept as a safety net going forward even though the RAM +bump addresses the actual root cause. ### 2026-07-02 — runner rewritten to submit jobs via the rc API (GUI job visibility)