From 52af38df6f00e40492d1e63c8f6d19920ffad0da Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Fri, 23 Oct 2026 10:35:16 +0200 Subject: [PATCH] =?UTF-8?q?hub-db-backup:=20wait=20for=20a=20snapshot=20be?= =?UTF-8?q?ing=20written,=20limit=207=20h=20(one=20slot=20gap=20+=201=20h)?= =?UTF-8?q?=20=E2=80=94=20the=202=20h=20limit=20refused=20the=20hub's=20ow?= =?UTF-8?q?n=20catch-up=20and=20mailed=20a=20false=20failure=20at=2010:28?= =?UTF-8?q?=20(R-1234,=20closed);=20tests=20red-proved?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- documentation/backlog/CLOSED-ITEMS.md | 6 ++++ hub/CHANGELOG.md | 2 +- scripts/CHANGELOG.md | 2 +- scripts/hub-db-backup/felhom-hub-db-backup | 15 +++++++++- scripts/hub-db-backup/test_hub_db_backup.py | 33 +++++++++++++++++++-- 5 files changed, 52 insertions(+), 6 deletions(-) diff --git a/documentation/backlog/CLOSED-ITEMS.md b/documentation/backlog/CLOSED-ITEMS.md index 9ae901c2..7337ec9e 100644 --- a/documentation/backlog/CLOSED-ITEMS.md +++ b/documentation/backlog/CLOSED-ITEMS.md @@ -26,6 +26,12 @@ --- +## 2026-10-23 day — the releases and the DooPlex hour (the operator's „go") + +| Row | What | Closed | Evidence | +|---|---|---|---| +| **R-1234** | **D34's first push refused the hub's own catch-up and mailed a false „hub-db-backup failed" to admin@.** Installing the 6-hourly timer at 10:28 made systemd catch up the missed 08:30 slot at once (`Persistent=true`), while the freshly deployed hub 0.167.0 was still writing its start-up snapshot (`hub-*.db.tmp`); the only finished one was 02:00 (8 h), above the new 2-hour limit → „the hub stopped snapshotting", `OnFailure` mail id `01a167e0…`. The 2 h limit was also stricter than the hub's own 6-hour catch-up, so any restart could repeat it. (P3) | CLOSED 2026-10-23 day, the same session — the push waits (≤ 20 min) for a snapshot being written, and the limit is one slot gap + 1 h (7 h); tests `test_d34_waits_for_a_snapshot_being_written` (reproduces the 10:28 run when the wait is removed), `…_a_restart_within_one_slot_is_not_an_alarm`, `…_two_missed_slots_are_refused`, each red-proved | `audits/day-2026-10-23/13-hubdb-6h-D34.txt` | + ## 2026-10-22 night — the seven decisions put into effect (full text of the rows: `git show 1100a344:documentation/backlog/OPEN-ITEMS.md`) | Row | What | Closed | Evidence | diff --git a/hub/CHANGELOG.md b/hub/CHANGELOG.md index 925cd2e7..d94e7350 100644 --- a/hub/CHANGELOG.md +++ b/hub/CHANGELOG.md @@ -19,7 +19,7 @@ box's controller). The checker now stands down for that declared state (the wait is the household's, it can take days); an undeclared consumed shape alarms as before. `TestR1230_AHeldBoxIsNotStuck`, red-proved. - `scripts/wire_contract_gate.py`: `wireguard.last_handshake_age_s` left the unread list (the hub reads it since 0.166.0). -- **D34 (operator yes 2026-10-23, R-232 G5) — the database snapshot every 6 hours.** The hub writes its `VACUUM INTO` snapshot at 02:00, 08:00, 14:00 and 20:00 Budapest (`dbsnap.Slots`, keep 2 unchanged), and the start-up catch-up fires when the newest is older than 6 h (`dbsnap.CatchUpAge`, was 24 h). DooPlex's push now runs :30 after each slot (`scripts/hub-db-backup`, refuses a newest copy older than 2 h, was 26 h), so the off-site hub copy is at most about 6.5 h old instead of a day. Added the same day as the build, on the operator's word (not soaked). Tests `TestD34_SlotsAreEverySixHours`, `TestR173_MainSchedulesTheDBSnapshot` (now the loop), and the script's `test_schedules` (the timer read against the hub's slots) and `test_d34_a_missed_slot_is_not_pushed_again` — each red-proved. +- **D34 (operator yes 2026-10-23, R-232 G5) — the database snapshot every 6 hours.** The hub writes its `VACUUM INTO` snapshot at 02:00, 08:00, 14:00 and 20:00 Budapest (`dbsnap.Slots`, keep 2 unchanged), and the start-up catch-up fires when the newest is older than 6 h (`dbsnap.CatchUpAge`, was 24 h). DooPlex's push now runs :30 after each slot (`scripts/hub-db-backup`, refuses a newest copy older than 7 h — one slot gap + 1 h — was 26 h; waits for a snapshot being written), so the off-site hub copy is at most about 6.5 h old instead of a day. Added the same day as the build, on the operator's word (not soaked). Tests `TestD34_SlotsAreEverySixHours`, `TestR173_MainSchedulesTheDBSnapshot` (now the loop), and the script's `test_schedules` (the timer read against the hub's slots) and `test_d34_a_missed_slot_is_not_pushed_again` — each red-proved. ## v0.166.0 (unreleased — built 2026-10-22 night, NOT deployed; the deploy is the operator's yes) — the clock-ahead tunnel alarm (R-1204) diff --git a/scripts/CHANGELOG.md b/scripts/CHANGELOG.md index a5b8fb90..abd96f36 100644 --- a/scripts/CHANGELOG.md +++ b/scripts/CHANGELOG.md @@ -1,7 +1,7 @@ ## 2026-10-23 — `release-copy/`: the released images and agent packages leave DooPlex nightly (D33, R-1227); `hub-db-backup/`: every 6 hours (D34) - **`release-copy/felhom-release-copy`** (new, DooPlex root, timer 01:40): the newest 3 release tags of felhom-controller, felhom-hub and felhom-samba (`skopeo copy --all --preserve-digests` into `dir:` — the registry's own bytes, so a push back gives the SAME digest; a `docker save` tar would not) and the newest 5 agent versions (binary + config bundle). Before anything leaves: the top manifest hashes to the registry's digest, every blob and child manifest to its name, every named blob is present, each agent file matches the registry's sha256; the staged tree ≤ the cap (3072 MB). Then `rsync --delete` to ep0's limited user `felhom-relcopy` (rrsync, one directory), and a `--checksum --dry-run` must show no difference before the success signal. Spoiled tags (0.315.0, 0.316.3) are never copied. 13 tests (`test_release_copy.py`), four red-proved. -- **`hub-db-backup/`** — the push runs at 02:30, 08:30, 14:30 and 20:30 (the hub snapshots every 6 hours since hub 0.167.0) and refuses a newest snapshot older than 2 h (was 26 h). Tests: the timer read against the hub's slots; a missed slot is refused. +- **`hub-db-backup/`** — the push runs at 02:30, 08:30, 14:30 and 20:30 (the hub snapshots every 6 hours since hub 0.167.0) and refuses a newest snapshot older than 7 h (one slot gap + 1 h; was 26 h), and waits (up to 20 min) while the hub is writing one. **Corrected the same day:** 2 h was shipped first, and its first run refused the timer's own catch-up while the hub's start-up snapshot was still being written — one false failure mail to admin@ at 10:28 (R-1234). Tests: the timer read against the hub's slots; two missed slots refused; a restart within one slot pushed; a snapshot being written waited for — each red-proved (the last reproduces the 10:28 run). ## 2026-10-23 — felhom-host-install.sh 1.36.0 (pushed; the tag `installer-v1.36.0` waits for the operator's yes): the uninstall removes the root-SSH drop-in (R-982, D4) diff --git a/scripts/hub-db-backup/felhom-hub-db-backup b/scripts/hub-db-backup/felhom-hub-db-backup index 177a5968..69efa1dc 100755 --- a/scripts/hub-db-backup/felhom-hub-db-backup +++ b/scripts/hub-db-backup/felhom-hub-db-backup @@ -12,7 +12,13 @@ set -eu CONF=${FELHOM_HUBBK_CONF:-/etc/felhom-hub-backup} STATE=${FELHOM_HUBBK_STATE:-/var/lib/felhom-hub-backup} TEXTFILE_DIR=${FELHOM_HUBBK_TEXTFILE_DIR:-/var/lib/node_exporter/textfile_collector} -MAX_AGE_H=${FELHOM_HUBBK_MAX_AGE_H:-2} # D34: the newest is ~30 min old at each push; 2 h refuses a missed slot +# D34: one slot gap + 1 h. The hub writes a catch-up snapshot at start when its newest is older than 6 h +# (dbsnap.CatchUpAge), so after any restart the newest is either < 7 h old or being written (waited for below). A hub +# that really stopped is refused at the second missed slot. (2 h was tried first, 2026-10-23: it refused the timer's own +# catch-up run while the hub's catch-up snapshot was still being written — a false "stopped snapshotting" mail.) +MAX_AGE_H=${FELHOM_HUBBK_MAX_AGE_H:-7} +WAIT_S=${FELHOM_HUBBK_WAIT_S:-1200} +POLL_S=${FELHOM_HUBBK_POLL_S:-15} NOW=${FELHOM_HUBBK_NOW:-$(date +%s)} . "$CONF/env" # PBS_REPOSITORY_PUSH, PBS_FINGERPRINT (no secrets in this file) @@ -25,6 +31,13 @@ mkdir -p "$STAGE"; chmod 700 "$STATE" "$STAGE" rm -f "$STAGE"/* trap 'if [ -f "$STAGE/hub.db" ]; then shred -u "$STAGE/hub.db" 2>/dev/null || rm -f "$STAGE/hub.db"; fi' EXIT +# A snapshot being written (hub-*.db.tmp) is waited for, so a push never takes the older one meanwhile (D34). +WAITED=0 +while kubectl -n felhom-system exec deploy/hub -- sh -c 'ls /data/snapshots/hub-*.db.tmp >/dev/null 2>&1'; do + [ "$WAITED" -ge "$WAIT_S" ] && { log "a snapshot is still being written after ${WAIT_S} s — taking the newest finished one"; break; } + [ "$WAITED" -eq 0 ] && log "a snapshot is being written in the hub pod — waiting for it (up to ${WAIT_S} s)" + sleep "$POLL_S"; WAITED=$((WAITED + POLL_S)) +done SNAP=$(kubectl -n felhom-system exec deploy/hub -- sh -c 'ls -1 /data/snapshots/hub-*.db 2>/dev/null | tail -n 1') || die "listing snapshots in the hub pod" [ -n "$SNAP" ] || die "no snapshot in the hub pod's /data/snapshots" NAME=${SNAP##*/} diff --git a/scripts/hub-db-backup/test_hub_db_backup.py b/scripts/hub-db-backup/test_hub_db_backup.py index 78070693..d8cffd1b 100644 --- a/scripts/hub-db-backup/test_hub_db_backup.py +++ b/scripts/hub-db-backup/test_hub_db_backup.py @@ -185,15 +185,42 @@ class Push(Base): self.assertEqual(self.pushed(), []) self.assertFalse(self.signal("felhom_hub_db_backup.prom")) - def test_d34_a_missed_slot_is_not_pushed_again(self): - # D34: snapshots every 6 h, so a newest copy 3 h old means the hub missed a slot — refuse, as for a day - self.snapshot(age_s=3 * 3600) + def test_d34_two_missed_slots_are_refused(self): + # D34: snapshots every 6 h; the limit is one slot gap + 1 h (7 h) — a newest copy 8 h old means the hub missed + # two slots, or stopped. RED-PROOF: MAX_AGE_H back to 26 → this pushes. + self.snapshot(age_s=8 * 3600) r = self.run_script(PUSH) self.assertNotEqual(r.returncode, 0) self.assertIn("stopped snapshotting", r.stderr) self.assertEqual(self.pushed(), []) self.assertFalse(self.signal("felhom_hub_db_backup.prom")) + def test_d34_a_restart_within_one_slot_is_not_an_alarm(self): + # the hub's catch-up fires only past 6 h, so after a restart the newest can be up to 6 h old — that is pushed, + # not refused (2 h refused it: the false mail of 2026-10-23 10:28). RED-PROOF: MAX_AGE_H 2 → this fails. + self.snapshot(age_s=int(5.9 * 3600)) + r = self.run_script(PUSH) + self.assertEqual(r.returncode, 0, r.stderr) + self.assertEqual(len(self.pushed()), 1) + + def test_d34_waits_for_a_snapshot_being_written(self): + # the 2026-10-23 10:28 case: the hub's catch-up snapshot is being written (hub-*.db.tmp) and the only finished + # one is 8 h old. The push must wait for the new one, not refuse the old. RED-PROOF: drop the wait loop → fails. + import threading + self.snapshot(age_s=8 * 3600) + snaps = self.j("pod", "snapshots") + tmp = os.path.join(snaps, "hub-%s.db.tmp" % stamp(int(time.time()))) + src = [os.path.join(snaps, n) for n in os.listdir(snaps) if n.endswith(".db")][0] + shutil.copy(src, tmp) + def finish(): + time.sleep(1.5) + os.rename(tmp, tmp[: -len(".tmp")]) + threading.Thread(target=finish).start() + r = self.run_script(PUSH, FELHOM_HUBBK_POLL_S="1", FELHOM_HUBBK_WAIT_S="20") + self.assertEqual(r.returncode, 0, r.stderr) + self.assertIn("being written", r.stdout) + self.assertEqual(len(self.pushed()), 1) + def test_truncated_copy_is_not_pushed(self): self.snapshot() r = self.run_script(PUSH, FAKE_TRUNCATE="1")