From 13504b90dec73171a52a7908c4b4cb9dfe4138bb Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Wed, 14 Oct 2026 00:24:18 +0200 Subject: [PATCH] =?UTF-8?q?Bench:=20plugcut.py=20=E2=80=94=20a=20real=20po?= =?UTF-8?q?wer=20cut=20on=20the=20HP=20with=20three=20ways=20back=20on;=20?= =?UTF-8?q?the=20night's=20round=20table=20written=20before=20round=201?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../audits/night-power-2026-10-13/README.md | 49 ++++++ .../night-power-2026-10-13/plant-sha256.txt | 20 +++ scripts/CHANGELOG.md | 7 + scripts/bench/README.md | 13 ++ scripts/bench/plugcut.py | 153 ++++++++++++++++++ scripts/bench/test_plugcut.py | 117 ++++++++++++++ 6 files changed, 359 insertions(+) create mode 100644 documentation/audits/night-power-2026-10-13/README.md create mode 100644 documentation/audits/night-power-2026-10-13/plant-sha256.txt create mode 100644 scripts/bench/plugcut.py create mode 100644 scripts/bench/test_plugcut.py diff --git a/documentation/audits/night-power-2026-10-13/README.md b/documentation/audits/night-power-2026-10-13/README.md new file mode 100644 index 00000000..cde4a690 --- /dev/null +++ b/documentation/audits/night-power-2026-10-13/README.md @@ -0,0 +1,49 @@ +# 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) + diff --git a/documentation/audits/night-power-2026-10-13/plant-sha256.txt b/documentation/audits/night-power-2026-10-13/plant-sha256.txt new file mode 100644 index 00000000..51747206 --- /dev/null +++ b/documentation/audits/night-power-2026-10-13/plant-sha256.txt @@ -0,0 +1,20 @@ +14189638d73b22ca70e52ed9c9268ee42e905db1b56968cb81ca2cdd9b8452b8 plant-01.bin +78c98745537aa24664ae74361fd3f20309f2934162b58b041e517836bcc417d6 plant-02.bin +badddd7dad4214cd6207cb29cfde3edc4e4baab3f63ea23f0c7520a8026992f9 plant-03.bin +08ee138f7a6446b8ffee5aed1198921ac3bb016d28d23fd92b4fa4f3c9631269 plant-04.bin +ede81bd0d1a89edd367f39bd71345a67178ce49d661b41cf558283da8c6d342f plant-05.bin +83d6d2fbd0c8db497216aeddda66c0383d0b9f0f5d527e971f18e4f8f38a96f9 plant-06.bin +dbaf2e9ce71cbad9c03208175e9ea582cfe8cdc72da4600301b3dc353a829a7f plant-07.bin +24066a276fb71410c1880be8e6d200c949efa55fd7699a70cf4cf0829c66f545 plant-08.bin +42612af9c55c9a33c131b1761c4cde0a97e41cc48f78c118f5249ae5cf87ec46 plant-09.bin +0aabce9d5e76b23626b5b04c3d35731568d8cc965e87006d4458e505d14c83dc plant-10.bin +ded0a457507c935a86d14abcb603b81747139fe107657f7a21ab8f2293747dd6 plant-11.bin +5ac05274d9f4cd0daebc62a02df0fc76045fb722a309a702a6a7874ec7a34ec5 plant-12.bin +6593d15aa3e580970660fc406cbfb7f4116499ba6d0f0495d6dab88c73238ce8 plant-13.bin +b1810d59dc548600c23f49e8ec56fc121f6d7ba67a4acaea4db1380f85cd70c8 plant-14.bin +8197f84a48f001fc1b056e96ca9bd7302d7bee232b449903486db7406e30203d plant-15.bin +32436352885d939d451d72cecf358558d2696cf25f5685d28686ce87029121ed plant-16.bin +b2556174851fff1c3c21cb8c28a14887d3459e33f96f894aa85882a402da83ab plant-17.bin +dd0ceedb353679e6d61876c4898477f29362e3d1fb3707ff67e78921ab03aac4 plant-18.bin +6c842b657602840f3e866971007feb00a16378838bebb37f04d4dcf826df6247 plant-19.bin +c088602f92943929018670b76607a77f621ab1c1997c022577a371834a4d4d45 plant-20.bin diff --git a/scripts/CHANGELOG.md b/scripts/CHANGELOG.md index 77c799cb..21fd0717 100644 --- a/scripts/CHANGELOG.md +++ b/scripts/CHANGELOG.md @@ -1,3 +1,10 @@ +## 2026-10-14 (night) — plugcut: a real power cut on the HP, with three ways back on + +- New `scripts/bench/plugcut.py` + `test_plugcut.py` (12 tests): refuses any plug but `hp` (N100 only with + `--allow-n100`), without `--i-mean-a-power-cut`, over 60 s without `--long`, over 3600 s. The relay off carries the + plug countdown (DP 9) in the same command; a detached watchdog is armed first; `finally:` re-arms. Red-proofed: each + of nine guards removed in turn, a test failed each. `plugswitch.py` is unchanged. + ## 2026-10-13 (night) — site_gates: the machine estimator moves from UNLISTED to TWINS (R-997) - `site_gates.py`: the `gepigeny`/`en/sizing` pair is a normal twin; `UNLISTED` is empty and gate 25 stays for the next diff --git a/scripts/bench/README.md b/scripts/bench/README.md index 2e3e8684..5fe0cd86 100644 --- a/scripts/bench/README.md +++ b/scripts/bench/README.md @@ -53,3 +53,16 @@ Same tools, `--plug hp` (config `~/.config/felhom-bench/plug-hp.json`, the plug the HP at `192.168.0.104`). `plugswitch.py off --plug hp` refuses until the HP's switched-off figure (`standby_w`) is measured. The wizard reads both plugs from one Tuya account; the credentials are `TUYA_DEVICE_ID_N100` and `TUYA_DEVICE_ID_HP` (renamed from `TUYA_DEVICE_ID` by the operator). + +## plugcut.py — a real power cut, on purpose (2026-10-13 night) + +`plugswitch.py off` stays „not a power-cut button". `plugcut.py` is the separate tool that cuts a running machine: + + ~/.venvs/plugmeter/bin/python scripts/bench/plugcut.py --plug hp --off-seconds 10 --i-mean-a-power-cut --log DIR + +- Only the plug `hp` (the N100's only with `--allow-n100`); only with `--i-mean-a-power-cut`; 1–60 s, up to 3600 s + only with `--long`. +- Three ways back on: the plug's own countdown (data point 9, sent in the same command as the off, then read back — + not shown running → on at once); a detached watchdog process started before the off (on after off-seconds + 15 s, + survives the tool being killed); `finally:` in the tool. +- One line per action to stdout and `DIR/plugcut.log`. Pinned by `test_plugcut.py` (12 tests, each guard red-proofed). diff --git a/scripts/bench/plugcut.py b/scripts/bench/plugcut.py new file mode 100644 index 00000000..084ebfe6 --- /dev/null +++ b/scripts/bench/plugcut.py @@ -0,0 +1,153 @@ +#!/usr/bin/env python3 +"""plugcut.py — a REAL power cut on a bench machine, with three ways back on. + + ~/.venvs/plugmeter/bin/python scripts/bench/plugcut.py --plug hp --off-seconds 10 --i-mean-a-power-cut \ + [--long] [--log DIR] + +This is NOT plugswitch.py. `plugswitch.py off` stays „not a power-cut button" (it refuses a running machine). +This tool cuts a running machine on purpose, so it is fenced: + + - only the plug `hp` (the N100's plug only with --allow-n100, the operator's „N100: B"; nothing else exists); + - only with --i-mean-a-power-cut; + - --off-seconds 1..60; up to 3600 only with --long. + +Three ways the power comes back, so a dead DooPlex or a killed tool cannot leave a machine without power: + 1. THE PLUG'S OWN COUNTDOWN (data point 9, countdown_1): sent in the SAME command as the relay off, then read + back. If the read-back does not show the countdown running, the relay is switched on at once. + 2. A WATCHDOG PROCESS, started (detached, own session) BEFORE the off: it sleeps off-seconds + 15 s and then + switches the relay on. It survives this process being killed. + 3. `finally:` in this process: the relay is switched on (and read back) whatever happened after the off. + +One line per action (UTC, plug, relay, countdown) to stdout and, with --log DIR, to DIR/plugcut.log. +The key and the device id are never printed. Pinned by scripts/bench/test_plugcut.py. +""" +import argparse, os, subprocess, sys, time +from datetime import datetime, timezone + +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +from plugswitch import load, device # noqa: E402 (same plug files, same connection settings) + +MAX_S = 60 +MAX_LONG_S = 3600 +WATCHDOG_EXTRA_S = 15 +LOG_DIR = None + + +def say(plug, msg): + line = f'{datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%S.%f")[:-3]}Z {plug} {msg}' + print(line, flush=True) + if LOG_DIR: + with open(os.path.join(LOG_DIR, 'plugcut.log'), 'a') as f: + f.write(line + '\n') + + +def refuse_reason(a): + """None when allowed, else why not. Pure: tested without a plug.""" + if a.plug not in ('hp', 'n100'): + return f'unknown plug {a.plug!r}' + if a.plug == 'n100' and not a.allow_n100: + return 'the N100 is not cut unless the operator said „N100: B" (--allow-n100)' + if not a.i_mean_a_power_cut: + return 'this cuts a running machine: add --i-mean-a-power-cut' + if a.off_seconds < 1: + return 'off-seconds must be at least 1' + limit = MAX_LONG_S if a.long else MAX_S + if a.off_seconds > limit: + return f'off-seconds {a.off_seconds} is over {limit}' + ('' if a.long else ' (longer needs --long)') + return None + + +def relay(dev): + s = dev.status() + d = s.get('dps', {}) if isinstance(s, dict) else {} + return d.get('1'), d.get('9') + + +def start_watchdog(plug, after_s): + """Detached process that switches the relay on after `after_s` s. Returns its pid.""" + args = [sys.executable, os.path.abspath(__file__), '--watchdog', str(after_s), '--plug', plug] + if LOG_DIR: + args += ['--log', LOG_DIR] + p = subprocess.Popen(args, stdin=subprocess.DEVNULL, stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL, + start_new_session=True) + return p.pid + + +def turn_on_verified(dev, plug, who, tries=5): + for i in range(tries): + try: + dev.turn_on() + on, cd = relay(dev) + say(plug, f'{who}: relay={"on" if on else "off?"} countdown={cd}') + if on: + return True + except Exception as e: # a slow plug read is late, not lost — try again + say(plug, f'{who}: try {i + 1} failed ({type(e).__name__})') + time.sleep(2) + return False + + +def cut(dev, plug, off_s, watchdog=start_watchdog, sleep=time.sleep, now=time.monotonic): + """The cut. Returns 0 when the relay is on again at the end.""" + pid = watchdog(plug, off_s + WATCHDOG_EXTRA_S) + say(plug, f'watchdog armed (pid {pid}, relay on after {off_s + WATCHDOG_EXTRA_S} s at the latest)') + try: + dev.set_multiple_values({'1': False, '9': int(off_s)}) + say(plug, f'CUT: relay off + countdown {off_s} s sent in one command') + on, cd = relay(dev) + say(plug, f'read back: relay={"on" if on else "off"} countdown={cd}') + if on is not False or not cd: + say(plug, 'countdown NOT shown running — switching on now (fail-safe)') + return 0 if turn_on_verified(dev, plug, 'fail-safe') else 1 + t0 = now() + sleep(off_s) + while now() - t0 < off_s + 10: + try: + on, cd = relay(dev) + except Exception: + on = None + if on: + say(plug, f'BACK: relay on by the plug countdown, +{now() - t0:.1f} s after the cut') + return 0 + sleep(1) + say(plug, 'the countdown did not switch the relay on within off-seconds + 10 s') + return 1 + finally: + try: + on, cd = relay(dev) + except Exception: + on = None + if not on: + turn_on_verified(dev, plug, 'finally re-arm') + + +def main(argv): + global LOG_DIR + ap = argparse.ArgumentParser(description=__doc__.split('\n')[0]) + ap.add_argument('--plug', default='hp') + ap.add_argument('--off-seconds', type=int, default=0) + ap.add_argument('--i-mean-a-power-cut', action='store_true') + ap.add_argument('--long', action='store_true') + ap.add_argument('--allow-n100', action='store_true') + ap.add_argument('--log') + ap.add_argument('--watchdog', type=int, help=argparse.SUPPRESS) + a = ap.parse_args(argv) + LOG_DIR = a.log + if a.watchdog is not None: # the detached watchdog: sleep, then make sure the relay is on + time.sleep(a.watchdog) + dev = device(load(a.plug)) + on, _ = relay(dev) + if on: + say(a.plug, 'watchdog: relay already on — nothing to do') + return 0 + return 0 if turn_on_verified(dev, a.plug, 'WATCHDOG') else 1 + why = refuse_reason(a) + if why: + print(f'REFUSED: {why}', file=sys.stderr) + return 2 + dev = device(load(a.plug)) + return cut(dev, a.plug, a.off_seconds) + + +if __name__ == '__main__': + sys.exit(main(sys.argv[1:])) diff --git a/scripts/bench/test_plugcut.py b/scripts/bench/test_plugcut.py new file mode 100644 index 00000000..032b494a --- /dev/null +++ b/scripts/bench/test_plugcut.py @@ -0,0 +1,117 @@ +#!/usr/bin/env python3 +"""Pins plugcut.py: its refusals, the countdown sent WITH the off, the watchdog armed BEFORE the off, +the fail-safe when the countdown does not show, and the `finally:` re-arm. A fake plug, no network.""" +import argparse, os, sys, unittest +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) +import plugcut # noqa: E402 + + +def args(**kw): + d = dict(plug='hp', off_seconds=10, i_mean_a_power_cut=True, long=False, allow_n100=False) + d.update(kw) + return argparse.Namespace(**d) + + +class FakePlug: + """Records every command. `countdown_works`: the plug turns itself on when the countdown ends.""" + def __init__(self, countdown_works=True, show_countdown=True, fail_after_off=False): + self.on, self.cd, self.log = True, 0, [] + self.countdown_works, self.show_countdown, self.fail_after_off = countdown_works, show_countdown, fail_after_off + self.clock = 0.0 + + def set_multiple_values(self, v): + self.log.append(('set', dict(v))) + if '1' in v: + self.on = v['1'] + if '9' in v and self.show_countdown: + self.cd = v['9'] + + def turn_on(self): + self.log.append(('on',)) + self.on, self.cd = True, 0 + + def status(self): + if self.fail_after_off and not self.on and any(e[0] == 'status' for e in self.log): + self.log.append(('status',)) + raise RuntimeError('plug gone') + self.log.append(('status',)) + return {'dps': {'1': self.on, '9': self.cd}} + + def tick(self, s): + self.clock += s + if self.countdown_works and not self.on and self.cd and self.clock >= self.cd: + self.on, self.cd = True, 0 + + +class Refusals(unittest.TestCase): + def test_allowed(self): + self.assertIsNone(plugcut.refuse_reason(args())) + + def test_without_the_long_flag(self): + self.assertIn('--i-mean-a-power-cut', plugcut.refuse_reason(args(i_mean_a_power_cut=False))) + + def test_n100_without_operator_word(self): + self.assertIn('N100', plugcut.refuse_reason(args(plug='n100'))) + self.assertIsNone(plugcut.refuse_reason(args(plug='n100', allow_n100=True))) + + def test_unknown_plug(self): + self.assertIn('unknown', plugcut.refuse_reason(args(plug='dooplex'))) + + def test_over_60_needs_long(self): + self.assertIn('--long', plugcut.refuse_reason(args(off_seconds=61))) + self.assertIsNone(plugcut.refuse_reason(args(off_seconds=3000, long=True))) + + def test_long_capped_at_3600(self): + self.assertIsNotNone(plugcut.refuse_reason(args(off_seconds=3601, long=True))) + + def test_zero_seconds(self): + self.assertIsNotNone(plugcut.refuse_reason(args(off_seconds=0))) + + +class Cut(unittest.TestCase): + def run_cut(self, plug, off_s=10): + order = [] + def watchdog(p, after): + order.append(('watchdog', after, len(plug.log))) + return 4242 + rc = plugcut.cut(plug, 'hp', off_s, watchdog=watchdog, sleep=plug.tick, now=lambda: plug.clock) + return rc, order + + def test_countdown_sent_with_the_off(self): + p = FakePlug() + rc, _ = self.run_cut(p) + first_off = next(e for e in p.log if e[0] == 'set' and e[1].get('1') is False) + self.assertEqual(first_off[1].get('9'), 10, 'the off must carry the countdown in the same command') + self.assertEqual(rc, 0) + self.assertTrue(p.on) + + def test_watchdog_armed_before_the_off(self): + p = FakePlug() + _, order = self.run_cut(p) + self.assertEqual(order[0][2], 0, 'the watchdog must start before any command reaches the plug') + self.assertEqual(order[0][1], 10 + plugcut.WATCHDOG_EXTRA_S) + + def test_failsafe_when_countdown_not_shown(self): + p = FakePlug(show_countdown=False) + rc, _ = self.run_cut(p) + self.assertTrue(p.on) + self.assertIn(('on',), p.log) + self.assertEqual(rc, 0) + + def test_finally_rearms_when_countdown_never_fires(self): + p = FakePlug(countdown_works=False) + rc, _ = self.run_cut(p) + self.assertEqual(rc, 1, 'a countdown that did not fire is a failed cut') + self.assertTrue(p.on, 'finally: must switch the relay back on') + + def test_finally_rearms_after_an_exception(self): + p = FakePlug(fail_after_off=True) + try: + self.run_cut(p) + except Exception: + pass + self.assertTrue(p.on, 'finally: must switch the relay back on after an error') + + +if __name__ == '__main__': + unittest.main()