felhom.eu/documentation/audits/night-power-2026-10-13/README.md

# Night 2026-10-13 → 14 — real power cuts on demo-hp, the estimator check, a night of wall power

Times are **UTC** (the boxes' schedules are in CEST = UTC+2; both are given where it matters). Tier 0 boxes only
(`runbooks/target-selection.md`): demo-hp and Tester 1 (VM 341 on it) are cut; the N100 is read only; DooPlex runs
the plug tools and reads the hub. Tool: `scripts/bench/plugcut.py` (new). No key, device id or token in this folder.

## Facts read before round 1 (22:10–22:40)

| Item | Value |
|---|---|
| N100 | **ON** — the operator pressed its power button at 21:48:43 (the prompt assumed it stays off). Read only tonight |
| HP host | AMD Ryzen Embedded V1756B, 29,994 MiB RAM, swap 8 GiB; guests 9201 (`memory: 25898`), 9202 (25898), VM 341 Tester 1 (8192); 9401 stopped |
| HP guest 9201 | 19 containers; 11 apps deployed (Home Assistant and Paperless among them; `paperless-ngx` and `romm` have no running container) |
| HP crash guard | `armed: false`, `kernel.panic 0` — tripped by today's 20:13 cut, re-arms 24 h later |
| Plug countdown | both plugs have data point 9 `countdown_1` (0–86400 s) and DP 38 `relay_status` = `memory` |
| SSH alias | both `ssh demo-hp` and `ssh hp` reach 192.168.0.104 from DooPlex; `nodes.md` is right |

**The HP's night schedule** (controller log 20:15:57 + agent journal):

| CEST | UTC | Job | Talks off-box? |
|---|---|---|---|
| 02:30 | 00:30 | db-dump (Tier 1) | no |
| 03:30 | 01:30 | tier2-backup, fill-watch; ep0 prunes households (DooPlex timeline) | ep0 prune — fenced |
| 04:15 | 02:15 | offbox-backup (Tier 3, restic → Storage Box) | **yes — fenced** |
| ~04:33–04:44 | ~02:33–02:44 | whole-guest vzdump, local (last 3 nights: 04:33, 04:36, 04:38 start, ~5.5 min) | no |
| ~04:45 | ~02:45 | OS step (`osupdate` guest + host, ring 0) | **fenced** |
| 05:10 / 05:30 / 06:00 | 03:10 / 03:30 / 04:00 | offsite abandon-sweep / proof / integrity | Storage Box — checked live before a cut |
| weekly | — | PBS whole-guest → ep0: HP last 2026-10-08 20:34, Tester 1 last 2026-10-11 20:02 (cadence 168 h) — **not due tonight** | — |

Fences before every cut (§9 rule 3): no `vzdump`, `proxmox-backup-client`, `restic`, `felhom-os-apply`, `apt`/`dpkg`
process on the HP host, guest 9201 or Tester 1; no scheduled start within 10 min; ≥ 10 min after the last full recovery.

## The round table (written 22:45, before round 1)

| Round | Planned UTC | The cut | Prediction |
|---|---|---|---|
| A + R1 | 23:00 | idle, 10 s, the countdown spike on the HP plug (the N100 is on: its plug is not a safe bench) | relay back on by the plug countdown; HP starts (BIOS „Previous State", set 20:10 today) in ≤ 40 s to ping; guests in 2–3 min; crash guard `last_boot_unclean: true`; hub `host_crash_restart` mail for demo-hp and Tester 1; no stale/down (well under 45 min) |
| R4 | 23:25 | flicker: off 2 s, on 3 s, off 2 s, on | as R1. Risk: the BIOS may treat the second off as a stop during POST and stay off |
| R6 | 23:50 | 50 min off (`--long`) | `host_stale` 30–45 min after the last report, for demo-hp AND Tester 1 (and `node_stale` from the controllers); at 50 min no `host_down` yet (90 min); on return: paired `*_recovered` mails + `host_crash_restart`; the 00:30 db-dump is missed while off and caught up after the start |
| R5 | 01:00 | 10 s off, 40 s after a power-on | the box is in POST/kernel start; it starts again; nothing is damaged (no guest was running) |
| — | 01:20–03:05 | **Part R1/R2 measurement** (no cut): the family set, rest, actions together, rest, across the 01:30 Tier 2, 02:15 Tier 3 and 02:33 vzdump | — |
| R2 | 03:15 | 10 s off at mid-import of a second 200-photo Immich upload | Immich DB recovers (postgres WAL replay); the half-import is not shown as done; the controller marks no app done that is not |
| R3 | 03:45 | 10 s off during a whole-guest backup started through the product | a `lock: backup` may stay in `pct config 9201` and stop the guest starting (the July finding); predict: the guest **does not** start by itself |
| — | 04:15–05:45 | Part R3: the 8 GB box test | — |

A round may move later; none is dropped without a line here saying why.

## Rounds (filled as they run)

### A + R1 — idle, 10 s, the countdown spike (moved earlier: 22:26:50 instead of 23:00)

| Step | Result |
|---|---|
| fences | clear 22:26:35 (control: a fake `vzdump-fence-control` process on the HP was caught, rc 1) |
| cut | 22:26:50.859 relay off + countdown 10 s in one command; read back `relay=off countdown=10`; **tool killed -9 at 22:26:50.993** |
| spike | relay on again by the **plug's own countdown** (~22:27:01; watts from the next read); the watchdog at +25 s found it on: „nothing to do". **The plug has a working countdown** |
| HP | **started by itself.** Hub host report 22:27:46 (+45 s), guest running 22:29:22, dashboard 200 22:29:44 (+2 min 43 s), 22 containers healthy 22:30:43 (+3 min 42 s) |
| Tester 1 | started by itself (VM `onboot`): report 22:28:20, dashboard 200 22:30:06, 10 containers healthy 22:31:04 (+4 min 3 s) |
| repairs | host: journal file „uncleanly shut down" replaced; ext4 journal recovery on root, drive and guest volumes; 11 + 1 orphan inodes deleted. **Each guest volume waited ~43 s in EXT4 multi-mount protection** („MMP interval 42 higher than expected") — about 1.5 min of the guest's start. Databases: postgres „not properly shut down → redo" (docmost, adventurelog), mariadb crash recovery (kimai, bookstack) — all finished at once |
| data | planted files 20/20 OK |
| crash guard | `last_boot_unclean: true`, `unclean_boots_24h: 3` on both boxes (still tripped from 20:13) |
| hub | `controller_started` for both; no stale/down. Crash mail: waits on the guard check 15 min after boot |
| prediction | right, except the guest start time (MMP — not predicted) |

### R4 — flicker: off 2 s, on 3 s, off 2 s, on (22:43:41, moved earlier from 23:25)

| Step | Result |
|---|---|
| cut | off 22:43:41.900 → on by countdown by 22:43:44.215; off 22:43:47.620 → on by 22:43:49.770 (`R4/plugcut.log`) |
| HP | **started by itself.** Ping 22:44:51 (+61 s after the last on), report 22:45:28, guest running 22:46:27, dashboard 200 22:46:49 (+3 min 0 s), 22 healthy 22:48:02 (+4 min 12 s) |
| Tester 1 | ping 22:45:31, dashboard 200 22:47:16, 10 healthy 22:48:13 |
| repairs | the same as R1: ext4 journal recovery, the same orphan counts, MMP waits; mariadb crash recovery (kimai). No new kind |
| data | planted files 20/20 OK |
| meter | the 2 s offs do not show in the plug's power readings (its reading lags; a 2 s value every ~2–7 s) — a cut shorter than ~5 s is seen only in `plugcut.log` |
| crash guard | `unclean_boots_in_window: 2`, `24h: 4` |
| prediction | right; the BIOS did not stop at the second off |

### R6 — 50 min off (23:01:04, moved earlier from 23:50 so it ends before the 00:30 UTC db-dump)

| Step | Result |
|---|---|
| cut | 23:01:04.495 relay off + countdown 3000 s; **on by the plug's countdown at 23:51:04.570**; the watchdog at +3015 s: „nothing to do". Plug read 0.0 W for all 691 readings |
| HP | **started by itself.** Ping 23:52:07 (+63 s), report 23:52:44, dashboard 200 23:54:09 (+3 min 5 s), 22 healthy 23:55:19 (+4 min 15 s). Tester 1 healthy 23:55:21 |
| hub, operator mails (all arrived, mailbox checked) | `node_stale` demo-hp 23:32, Tester 1 23:33 („No report received for 45m"); `host_stale` 23:45 / 23:46 („no report for 45m"); `host_recovered` 23:53 („was stale for 8m" / „7m"); `node_recovered` 23:55 („was stale for 23m" / „22m"). **Paired, true, F5's recovery leg seen live** |
| hub, household | nothing: „customer mail skipped — no unanswered customer down mail" (the household is told only at `host_down`, 90 min) — consistent |
| finding | the recovery mails say how long the box was *stale* (8 min), not how long it was *gone* (51 min) — an operator reading only the recovery mail under-reads the outage |
| repairs, data | as R1; planted files 20/20 OK |
| prediction | right on stale timing and pairing; wrong on the db-dump (the box was back before 00:30, nothing was missed) |

### R5 — 10 s off, then 10 s off again 40 s after the power came back (00:08:11, moved earlier from 01:00)

| Step | Result |
|---|---|
| cut | off 00:08:11.833 → on 00:08:21.922 (countdown); at +40 s (00:09:02) **the host already answered ping** — the second cut hit early user space, not the BIOS; off 00:09:02.290 → on 00:09:12.402 |
| HP | **started by itself.** Ping 00:09:58 (+46 s), report 00:10:25, dashboard 200 00:11:50 (+2 min 38 s), 22 healthy 00:13:03 (+3 min 51 s). Tester 1 healthy 00:13:14 (the VM had not reached its own boot record before the second cut) |
| journal | the interrupted boot left a 0-second journal entry (`journalctl --list-boots`: 02:08:50 CEST); no new kind of repair; the same ext4 recovery, orphans and DB redo |
| crash guard | HP `unclean_boots_in_window: 3`, `24h: 7`; Tester 1 2 / 6 |
| data | planted files 20/20 OK |
| prediction | right |

### R3 — 10 s off during the night's own whole-guest backup (02:52:05; the planned product-started backup was not needed)

| Step | Result |
|---|---|
| backup | the agent's local vzdump of 9201 started 02:42:18 (4 min later than the last three nights); at 02:52:05 it was still writing: `.tar.dat` **12.4 GB** (last night's whole archive: 4.9 GB; the space preflight planned for 7.2 GB from the last archive). The bench's apps had put ~1.8 GB of photos, videos and uploads on the guest's system disk, plus their images |
| fences | the HP's other jobs and Tester 1 clear; Part R2's sampling ended at 02:51:52 and its evidence was copied first |
| cut | 02:52:05.808 off → 02:52:15.909 on (countdown), `lock: backup` on 9201 at the cut |
| lock | agent at 02:52:56: „stale-lock: a vzdump backup is **genuinely in-flight** — leaving the lock (NOT stale)" — **wrong after a power cut** (nothing can be in flight on a fresh boot). Proxmox's own `pve-guests` start-all at the same second: „**removed left over backup lock from '9201'!**" and started it. Prediction („the guest does not start") **wrong** — Proxmox 9 clears it |
| HP | ping 02:52:59 (+43 s), report 02:53:30, dashboard 200 02:55:02 (+2 min 46 s), **31** containers healthy 02:56:13 (+3 min 57 s). Tester 1 healthy 02:56:24 |
| leftover | the half-written `vzdump-lxc-9201-2026_10_14-04_42_18.tar.dat` (12.2 GB) and its `.tmp` folder stay in `/var/lib/vz/dump`; the host root file system is at **92 %** (3.0 GB free) — watched below |
| data | planted files 20/20 OK; the database redo as before |

### R2 — 10 s off at mid-import: a second 200-photo Immich upload (03:09:27; planned 03:15)

| Step | Result |
|---|---|
| import | started 03:08:59 in guest 9201 (each photo made unique so Immich does not skip it as a duplicate); the cut came when the 100th upload had answered (the 101st answered **201 Created** at 03:09:27, 0.3 s before the cut) |
| HP | ping 03:10:19 (+42 s), report 03:10:48, dashboard 200 03:12:14 (+2 min 37 s), 31 healthy 03:13:53 (+4 min 16 s). Tester 1 healthy 03:13:55 |
| Immich after (`R2/immich-check.txt`, every asset: stored checksum vs the bytes sent, original, thumbnail) | **101** new assets listed. **19** whole. **81** with the original intact (checksum and size right) but an **empty thumbnail and preview** — 162 zero-byte files on disk (`R2/zero-files.txt`). **1** (the upload answered 201 at the cut) listed, but its original is **gone** (HTTP error on original and thumbnail). Immich's job queues are empty: **nothing repairs them**; the ML jobs that ran at start logged „Machine learning repository not been setup" (the ML container was still starting) |
| other files | a 40-byte file written 30 s before the cut (`/root/sizing/r2-env`, the bench's own) came back **0 bytes**: ext4 kept the name, not the data. The same effect as the thumbnails — data written in the last ~30 s before a cut can come back empty |
| data | planted files (written hours before, `sync`ed) 20/20 OK |
| prediction | „nothing half-written is shown as done" — **wrong**: 82 of 101 new photos are shown as done and are broken (81 without a picture, 1 without the photo) |

### The leftover half-backup (after R3), watched without help

| UTC | What the box did alone |
|---|---|
| 03:01:41 | agent retried the local backup: hub event `whole_guest_backup_failed` (error, operator mail) „retrying with backoff (next attempt in 15m0s)" |
| 03:08:03 | `backup FAILED: target=local vmid=9201 err="skipped: not enough space: local has 2.9 GiB free; the last archive of guest 9201 was 4.6 GiB…"` — the space is held by the half-written 12.2 GB archive from the cut. **Nothing removes it**; every retry will fail the same way |

## What the operator and the household were told (hub log `hub-night-log.txt` + the operator mailbox, both read)

| Round | Operator mail | Household mail | True? |
|---|---|---|---|
| R1 (22:26) | `host_crash_restart` demo-hp 22:42, Tester 1 22:43 (sent by the crash-guard check 15 min after boot) | none | true |
| R4 (22:43) | crash recorded 23:00, mail **suppressed — cooldown** (one mail per box per cooldown) | none | the hub page has it; the mailbox under-counts restarts |
| R6 (23:01, 50 min) | `node_stale` 23:32/23:33, `host_stale` 23:45/23:46, `host_recovered` 23:53, `node_recovered` 23:55, `host_crash_restart` 00:07 | none („no unanswered customer down mail") | true; the recovery text under-reads the outage (R-1005) |
| R5 (00:08, two cuts) | two `host_crash_restart` for demo-hp at 00:25, suppressed — cooldown | none | as R4 |
| Part R1 load (00:51) | `health_degraded` 00:51 („Rendszer állapot romlott"), `health_recovered` 00:56 | none | true (the bench's three heavy apps at once) |
| night off-site (02:18) | `backup_run_failures` „3 of 3 apps failed to back up (offsite run)" | none | true — the bench apps (R-203's class); subject says „3 of 3" though 11 other apps were backed up |
| R3 (02:52) | `host_crash_restart` 03:08; `whole_guest_backup_failed` 03:01 (then suppressed — cooldown at 03:19); `whole_guest_backup_recovered` 05:28 after the hand clean-up | none | true |
| R2 (03:09) | crash recorded 03:25, suppressed — cooldown | none | as R4 |
| N100 (all night) | **none** — no mail for demo-felhom after 2026-10-13 13:58 | none | true (it ran normally) |

## Teardown — what was done by hand, and why

| UTC | Act | Why |
|---|---|---|
| 04:40 | removed the half-written `vzdump-lxc-9201-2026_10_14-04_42_18.tar.dat` + `.tmp` (12.2 GB) | R3 was fully recorded; every retry was skipping for space. The next retry at 05:17 **succeeded** (`whole_guest_backup_recovered` 05:28) — proves the cause (R-1006) |
| 07:28 | removed the 05:17 archive (14.4 GB — it held the bench's photos, videos and uploads) and pressed „back up now" through the product (`POST /api/guest-backup/trigger`, 200) | with it the next preflight would have needed ~21 GB of 5.5 GB free; the new archive: 5.6 GB at 07:35, host root 63 %. A daytime backup may move the box's 24 h backup clock (STATUS-HISTORY 2026-10-08) |
| 05:59–06:02 | removed the bench apps on 9201 through the product (immich, jellyfin, nextcloud, vaultwarden: stop 200, remove 200, no leftovers), the bench folder `/mnt/sizing-bench`, the planted files | bench clean-up |
| 06:05 / 07:42 | deleted the 20 bench scans from 9201's Paperless and the 20 from 9202's (Django shell, by original file name `bench-night*`; both had 0 documents of their own) | they were the bench's |
| 07:42 | removed `/root/sizing` on the host, 9201 and 9202 (samplers, content; every TSV was copied off first) | bench clean-up |

Left as found: 9201 `memory: 25898` (untouched), 9202 `memory: 25898` (set to 4096 for Part R3 from 03:17 to 05:57, then back),
Tester 1 running (never stopped), 9201's 11 apps and 22 containers, 9202's Paperless. HP crash guard: tripped (re-arms 24 h
after the last unclean boot, 03:10 → 2026-10-15 03:10).

## Power (`power.json`, `hp-power.csv`, `n100-power.csv`; no gap over 20 s in either file)

| | HP t740 | N100 |
|---|---|---|
| at rest | 24–27 W (median 24.1 W; 9201 with 11 apps, Tester 1's VM, scratch 9202) | 7.3 W median, 8.5 W average |
| the night 22:12–06:00 (7.8 h) | 245 Wh — a bench night (6 rounds, the estimator check), not a household night | **66 Wh** — a normal night |
| boots after a cut (power-on → all healthy) | 72–81 W peak, 2.7–3.4 Wh each (R1 2.7, R4 3.0, R6 2.9, R5 2.7, R3 3.0, R2 3.4) | — |
| backups | Tier 3 restic 43.8 W avg (2.6 Wh); whole-guest vzdump 39–44 W avg, 7.0–7.5 Wh | the backup window 02:30–02:58: 19.8 W max |
| heavy work | three apps at once 71 W avg, 81.6 W max; the family set on a 4 GB guest 51.9 W avg for 50 min (swap thrash) | — |
| plugs at the end (07:5x) | relay **on**, 22.5 W | relay **on**, 6.6 W (the machine runs) |