772956d214
The events leg the previous commit reported as not-reached is now done. The operator relayed the claim code (the only route: bcrypt-hashed hub-side, emailed only), the two storage paths were registered through the real POST /api/storage/register, and the cycle ran on the fresh box: 07:20:04 backup_target_absent (error) Cel meghajto <- TARGET, specific 07:22:34 backup_target_restored (info) Cel meghajto <- its matching pair 07:24:04 storage_disconnected (error) Adat meghajto <- NON-target, generic 07:25:34 storage_reconnected (info) Adat meghajto All four at the hub; gate fired in 3 s. Two matched pairs, correctly discriminated -- and discrimination is proven NON-trivially for the first time, since both prior runs had the target itself emit the generic event. Over-correction passes on a positive observable, with two RETURNED lines proving the gate was ticking. 00-capability-map row F: PARTIAL -> PROVEN-LIVE with the evidence and the caveat. R-120 filed: the golden bakes controller 0.185.1, which PREDATES R-114 + R-112, so a freshly installed box shows the customer the WRONG absent-target message -- observed live on the drill box: the generic "the backup is on the same disk as the system" copy (false; the target is a drive that vanished) plus an offer of the other drive as the remedy. That is E2D 5.3's exact payload, still reachable on any new install. R-115's class one layer up -- R-111 closed by re-baking the golden, 0.186.0 then shipped, the golden did not move, and the gap reopened silently; this time the stale artifact carries a customer-facing falsehood in exactly the state R-116 now alarms about correctly. Teardown recorded for all three layers, hub layer gate-blocked with the command.
283 lines
19 KiB
Markdown
283 lines
19 KiB
Markdown
# R116-v0116-2026-07-30 — R-116 CLOSED: the specific alarm and its matching recovery, both on the wire
|
||
|
||
**Run:** R-116 join task, CC on DooPlex, 2026-07-30. Agent **v0.116.0** built, published, vouched, and
|
||
**installed by a fresh box from the Day-0 manifest**. **Result: ALL claims PASS.**
|
||
|
||
| Claim | Verdict |
|
||
|---|---|
|
||
| **The fix is effective live** — the absent target row carries the flag **and** the key the gate uses | ✅ **PASS**. `isTarget["/mnt/felhom-drives/cel"] = true` (was `false` through v0.115.0) |
|
||
| **C5 — `backup_target_absent` / `_restored` on the wire, paired** | ✅ **PASS.** `backup_target_absent` **(error)** on detach, `backup_target_restored` **(info)** on return, same drive, both at the hub. Gate fired in **3 s** |
|
||
| **Discrimination — target ⇒ specific, non-target ⇒ generic** | ✅ **PASS, and NON-trivially for the first time.** Same box, minutes apart: target → `backup_target_absent`; non-target → `storage_disconnected` |
|
||
| **No over-correction** | ✅ **PASS** with a positive observable — 0 ABSENT lines / 0 drive events over 2m14s with both drives present, while 2 `RETURNED` lines prove the gate ticked |
|
||
| **R-114 not regressed by the fix** | ✅ **PASS at the payload layer** (no row combines the flag with a mount path) + unit-pinned. ⚠️ **not confirmable on this box** — it ran controller 0.185.1 from the golden, which predates R-114 → **R-120** |
|
||
|
||
## 1. Baselines as actually running
|
||
|
||
| | `main` | running | a FRESH box gets |
|
||
|---|---|---|---|
|
||
| agent | **0.116.0** (`21b0164`) | felhom-pve 0.115.0 · demo-hp 0.113.0 · **drill `sess-e-5d4427` 0.116.0** | **0.116.0** (vouched this run) |
|
||
| controller | 0.186.0 (`b331f18`) | felhom-pve **0.186.0** · demo-hp **0.185.1** · drill **0.185.1** | golden bakes **0.185.1** |
|
||
| hub | 0.81.0 | 0.81.0 | `min_agent` 0.113.0 · `min_controller` 0.156.0 |
|
||
| `felhom.eu` | `1aa1bd1` | — | — |
|
||
|
||
**The golden bakes controller 0.185.1** — which is why the fix had to land in the agent: a controller-side
|
||
fix would not reach a fresh box without a re-bake, whereas the agent channel serves the newest vouched
|
||
version immediately. Confirmed by this run: the drill box installed **0.116.0** unaided.
|
||
|
||
## 2. §5's three publish observables, as returned
|
||
|
||
```
|
||
(1) registry, independent GET of the published bytes:
|
||
HTTP 200 bytes=14022347
|
||
b47c5c4dab641ee57e2cf5893c2aebf1806a41c376ab06322342b02c86940a98 /tmp/rt-0.116.0
|
||
/tmp/rt-0.116.0 --version → felhom-agent 0.116.0
|
||
(2) hub Day-0 manifest, read BACK after the POST (not the 303):
|
||
agent_version: SELECTED=['0.116.0'] agent_sha256 = b47c5c4dab641ee5…
|
||
golden_version: SELECTED=['0.185.1'] min_agent = 0.113.0
|
||
wrapper_sha256 = 104db0a4401f65bb… (re-checked against configs/felhom-pbs-apply — NO drift)
|
||
(3) the box under test reports it running:
|
||
hub log → Artifact manifest served for customer sess-e (agent=0.116.0 golden=0.185.1)
|
||
host row → sess-e-5d4427 … 0.116.0 ONLINE
|
||
on the box → felhom-agent --version → felhom-agent 0.116.0
|
||
```
|
||
|
||
`min_agent` deliberately **not** raised: controller v0.185.0 declares MinAgent 0.113.0, and raising it
|
||
would hold demo-hp (0.113.0) for no reason. The golden was not moved — the controller is unchanged.
|
||
|
||
## 3. The rig — real pipeline, no bypass
|
||
|
||
**Machine: `demo-hp`**, per `runbooks/target-selection.md` (Tier 0, the designated drill+build VM host).
|
||
**This differs from the previous R-116 run, which used the DooPlex fixture** — the document says DooPlex is
|
||
Tier 2 and its `drill.qcow2` is a bake fixture, not a drill target, so this run followed the document.
|
||
|
||
VM **9401** `r116-drill`: nested PVE, 8 GiB/4 vCPU cpu=host, OVMF, disks on a **dir storage
|
||
`r116-images` at `/mnt/nvme-1tb` root** — **not** `local-lvm` (over-subscribed thin pool hosting a live
|
||
guest). Installed from the **real v1.25.0 felhom ISO** already on demo-hp, through the **real day-0**:
|
||
self-register (appliance 13, pairing `D54-DG5`) → operator bind to `sess-e` → credentials delivered once →
|
||
guest 9201 provisioned from the vouched golden → `controller_started (0.185.1)` → reports flowing.
|
||
|
||
Drives, both enrolled through the **real endpoints** (`/disks/format` → `/disks/assign` →
|
||
`/disks/guest-attach` → `/backup/target`), no hand-set state:
|
||
|
||
| | device | host mount | guest bind | role |
|
||
|---|---|---|---|---|
|
||
| target | `/dev/sdb` (scsi1) | `/mnt/cel` | `/mnt/felhom-drives/cel` | primary backup target (`felhom-backup`, `is_mountpoint 1`) |
|
||
| non-target | `/dev/sdc` (scsi2) | `/mnt/adat` | `/mnt/felhom-drives/adat` | user-data only |
|
||
|
||
`backup tier armed target=felhom-backup … primary=true` after the required restart.
|
||
|
||
Device loss is a **real hot-detach** (`qm set 9401 --delete scsi1`); the volume survived as `unused0` and
|
||
was reattached, so the present-state control is re-runnable.
|
||
|
||
## 4. The payloads — PASS, and this is what v0.115.0 could not do
|
||
|
||
Host state at the absent capture, identical to every prior run:
|
||
|
||
```
|
||
ls /dev/sdb → No such file or directory
|
||
findmnt /mnt/cel → rc=1 (not mounted)
|
||
pvesm status → unable to activate storage 'felhom-backup' - directory is expected to be a
|
||
mount point but is not mounted: '/mnt/cel'
|
||
felhom-backup dir inactive 0 0 0
|
||
```
|
||
|
||
### The target drive's row, all three states
|
||
|
||
| state | rows | rows for the target | `mount_path` | `guest_path` | `backup_target` | `bound_under_parent` | `state` | `role` |
|
||
|---|---|---|---|---|---|---|---|---|
|
||
| PRESENT | 4 | **1** | `/mnt/cel` | `/mnt/felhom-drives/cel` | **`true`** | `true` | attached | user-data |
|
||
| **ABSENT** | 4 | **1** | **`""`** | **`/mnt/felhom-drives/cel`** | **`true`** | `false` | disconnected | system |
|
||
| RETURNED | 4 | **1** | `/mnt/cel` | `/mnt/felhom-drives/cel` | **`true`** | `true` | attached | user-data |
|
||
|
||
**Exactly one row in every state** — the registry row for the target is deduped by guest path in the
|
||
absent state (`registry-row-for-target = 0` in all three captures). Before this fix the absent state
|
||
carried it **twice**.
|
||
|
||
### `driveTargetByPath` computed from the captured absent payload
|
||
|
||
```
|
||
driveTargetByPath = {'/mnt/felhom-drives/cel': True,
|
||
'/mnt/felhom-drives/adat': False, '/mnt/adat': False}
|
||
isTarget[/mnt/felhom-drives/cel] = True ← was FALSE through v0.115.0
|
||
```
|
||
|
||
`notifyDriveAbsent` therefore takes the **specific** branch. RETURNED gives `True` as well, so the pair
|
||
matches.
|
||
|
||
### The three guards, from the same payload
|
||
|
||
- **R-114 preserved.** No row has `backup_target: true` **and** `mount_path != ""`. The absent target row
|
||
reports `mount_path: ""`, so `backup_target_offer.go:79` does **not** match and R-114's `TargetAbsent`
|
||
branch stays reachable. This is why option (a) was rejected — see `felhom-agent/REPORT.md`.
|
||
- **No over-correction.** `bound_under_parent: false` on the absent row, so
|
||
`present[gp] = … || d.BoundUnderParent` stays false and the Stop branch is still reachable.
|
||
- **Discrimination, payload layer.** The non-target `adat` carries `backup_target` **absent ⇒ false** on
|
||
both its keys, in both states. So the two are now genuinely distinguishable — which is the thing both
|
||
prior runs could not show.
|
||
|
||
### Raw payloads
|
||
|
||
Absent (all 4 rows, verbatim):
|
||
|
||
```json
|
||
{"ok":true,"data":{"disks":[{"name":"felhom-backup","type":"local-dir","state":"disconnected","backing_device":"","mount_path":"","class":"","role":"system","data_bearing":false,"total_bytes":0,"used_bytes":0,"used_fraction":0,"durable_id":"path:/mnt/cel","guest_attached":false,"backup_target":true,"guest_path":"/mnt/felhom-drives/cel","bound_under_parent":false,"smart":{"health":"UNKNOWN","temperature_c":null,"power_on_hours":null,"reallocated_sectors":null,"pending_sectors":null,"offline_uncorrectable":null,"critical_warning":null,"media_errors":null,"percentage_used":null}},{"name":"local","type":"local","state":"attached","backing_device":"","mount_path":"","class":"","role":"system","data_bearing":false,"total_bytes":14484905984,"used_bytes":5096075264,"used_fraction":0.351819699045967,"durable_id":"path:/var/lib/vz","guest_attached":false,"bound_under_parent":false,"smart":{"health":"UNKNOWN","model_name":"QEMU QEMU HARDDISK","temperature_c":0,"power_on_hours":null,"reallocated_sectors":null,"pending_sectors":null,"offline_uncorrectable":null,"critical_warning":null,"media_errors":null,"percentage_used":null}},{"name":"local-lvm","type":"lvmthin","state":"attached","backing_device":"","mount_path":"","class":"","role":"system","data_bearing":false,"total_bytes":12675186688,"used_bytes":4224639723,"used_fraction":0.33329999999129,"durable_id":"pve/data","guest_attached":false,"bound_under_parent":false,"smart":{"health":"UNKNOWN","temperature_c":null,"power_on_hours":null,"reallocated_sectors":null,"pending_sectors":null,"offline_uncorrectable":null,"critical_warning":null,"media_errors":null,"percentage_used":null}},{"name":"d248508a-0c4f-466f-9c43-0dae988efc62","type":"usb","state":"attached","backing_device":"/dev/sdc","mount_path":"/mnt/adat","class":"","role":"user-data","data_bearing":false,"total_bytes":8350298112,"used_bytes":2125824,"used_fraction":0.00025458061155266215,"durable_id":"uuid:d248508a-0c4f-466f-9c43-0dae988efc62","guest_attached":false,"guest_path":"/mnt/felhom-drives/adat","bound_under_parent":true,"smart":{"health":"UNKNOWN","model_name":"QEMU QEMU HARDDISK","temperature_c":0,"power_on_hours":null,"reallocated_sectors":null,"pending_sectors":null,"offline_uncorrectable":null,"critical_warning":null,"media_errors":null,"percentage_used":null}}],"guest_boot_id":"1785394603-28275","vmid":9201}}
|
||
```
|
||
|
||
Present and returned payloads: `d-PRESENT.json` / `d-RETURNED.json`, on the box at `/root/` and in the
|
||
session scratchpad. The target row differs from the absent one only in the fields tabulated above.
|
||
|
||
## 5. Where R-117 interfered — and it did
|
||
|
||
**Reproduced again, fourth consecutive run, and on real hardware this time:**
|
||
|
||
```
|
||
after reattach: host findmnt /mnt/cel → /dev/sdd
|
||
guest findmnt /mnt/felhom-drives/cel → /dev/sdb[/felhom-data] rw,relatime,shutdown
|
||
guest read through the bind → GUEST-READ-EIO
|
||
/disks says → state attached, bound_under_parent TRUE
|
||
```
|
||
|
||
**How it interferes with reading this run:** the reattach leg's `isTarget = true` and
|
||
`bound_under_parent = true` are *correct as answers to the questions this fix asks*, but they are read off
|
||
a drive whose guest namespace is **dead**. So "the drive came back healthy" cannot be concluded from the
|
||
reattach capture — only "the flag and the key rejoined on one row", which is what was under test. When the
|
||
events leg runs, the `Return` branch will fire against a dead bind, so a `backup_target_restored` there
|
||
proves pairing, **not** recovery. Recorded, not fixed (R-117 has its own row).
|
||
|
||
## 6a. C5 + discrimination — PASSED, the full four-event sequence
|
||
|
||
The claim gate (§6b) was cleared with an operator-relayed code, the two paths registered through the real
|
||
`POST /api/storage/register`, and the cycle run. Controller log, verbatim, one continuous run:
|
||
|
||
```
|
||
07:20:03 [WARN] [gate] drive ABSENT /mnt/felhom-drives/cel — stopped+blocked 0 app(s): []
|
||
07:20:03 [ERROR] [gate] the ABSENT drive /mnt/felhom-drives/cel is the WHOLE-GUEST BACKUP TARGET
|
||
— the system backup cannot run until it returns
|
||
07:20:04 [INFO] Event pushed: backup_target_absent (error) — A rendszermentés meghajtója nem érhető el:
|
||
Cel meghajto (/mnt/felhom-drives/cel)
|
||
07:22:34 [INFO] [gate] drive RETURNED /mnt/felhom-drives/cel — re-attached + restarted gate-stopped apps
|
||
07:22:34 [INFO] Event pushed: backup_target_restored (info) — A rendszermentés meghajtója újra elérhető:
|
||
Cel meghajto (/mnt/felhom-drives/cel)
|
||
07:24:03 [WARN] [gate] drive ABSENT /mnt/felhom-drives/adat — stopped+blocked 0 app(s): []
|
||
07:24:04 [INFO] Event pushed: storage_disconnected (error) — Meghajtó váratlanul leválasztva: Adat meghajto
|
||
07:25:34 [INFO] [gate] drive RETURNED /mnt/felhom-drives/adat — re-attached + restarted gate-stopped apps
|
||
07:25:34 [INFO] Event pushed: storage_reconnected (info) — Meghajtó újra csatlakoztatva: Adat meghajto
|
||
```
|
||
|
||
All four **reached the hub** (`Event from sess-e: …` at 09:20:03 / 09:22:34 / 09:24:04 / 09:25:34 CEST).
|
||
|
||
| # | drive | event | severity | pair |
|
||
|---|---|---|---|---|
|
||
| 1 | **target** `cel` | **`backup_target_absent`** | error | ↔ 2 |
|
||
| 2 | **target** `cel` | **`backup_target_restored`** | info | ↔ 1 |
|
||
| 3 | non-target `adat` | `storage_disconnected` | error | ↔ 4 |
|
||
| 4 | non-target `adat` | `storage_reconnected` | info | ↔ 3 |
|
||
|
||
**Two matched pairs, correctly discriminated.** This is what R-116 existed to produce and what two prior
|
||
runs could not: both of those had the *target* emit the generic event, so "non-target ⇒ generic" proved
|
||
nothing about telling them apart. Here the two cases ran on **the same box, four minutes apart**, and
|
||
diverged.
|
||
|
||
**Over-correction guard — positive observable, not an absent log line.** Window 07:26:51Z → 07:29:05Z with
|
||
both drives present: **0** `drive ABSENT` lines, **0** drive events, and
|
||
`{"degraded":false,"label":"Cel meghajto","target":"felhom-backup"}`. That the gate was *running* during
|
||
the window is established independently by the two `[gate] drive RETURNED` lines earlier in the same
|
||
container's log — so the silence is a decision, not a dead loop.
|
||
|
||
Also emitted: `health_critical (error)` at 07:21:32 while the target was away, and its recovery. Expected
|
||
— the box's overall health reflects a missing backup target — recorded so the event count reconciles.
|
||
|
||
## 6b. The claim gate — the one genuine human step, again (→ R-119)
|
||
|
||
`planDriveGates` iterates `s.settings.GetStoragePaths()`. The drill controller has **none**:
|
||
|
||
```
|
||
controller log → [WARN] Storage paths: no storage paths registered
|
||
```
|
||
|
||
Registering one requires the controller's storage API, and **every** route is behind the claim gate:
|
||
|
||
```
|
||
GET /api/storage/backup-target (Host: felhom.sess-e.test) → 401 {"ok":false,"error":"dashboard not yet claimed"}
|
||
GET /api/storage/paths → 401
|
||
GET /api/storage/list → 401
|
||
```
|
||
|
||
The claim code is **bcrypt-hashed in the hub and only ever emailed** (`claim/engine.go`), and the
|
||
self-bind link is likewise mint-and-email — `handleSelfBindLinkSend` (`selfbind_mint.go:139-161`) only
|
||
ever renders a flash, never the token. **There is no operator-side route to either secret**, which is the
|
||
same wall E2D hit and named "the one genuine human step".
|
||
|
||
A fresh code (**generation 2**) was emailed by `POST /configs/sess-e/claim-resend` and **the operator
|
||
relayed it**, which is the only route that exists. Claim submitted through the real `POST /claim` (its own
|
||
pre-auth HMAC CSRF: GET the page, carry the token **and** its cookie), then login, then session-CSRF for
|
||
the writes. Positive discriminator that the gate moved, as E2D recorded:
|
||
|
||
```
|
||
before: {"ok":false,"error":"dashboard not yet claimed"}
|
||
after: {"ok":false,"error":"authentication required"} (unauthenticated)
|
||
authed: {"data":{"degraded":false,"known":true,"label":"/mnt/felhom-drives/cel","target":"felhom-backup"},"ok":true}
|
||
```
|
||
|
||
**The cost is real and recurring: three sessions have now stopped at this wall.** → **R-119**.
|
||
|
||
## 7. Teardown — layers 1–3, per the §13 paragraph this task added
|
||
|
||
| layer | item | disposition |
|
||
|---|---|---|
|
||
| 1 — machine | VM **9401** `r116-drill` + all four volumes | **DESTROYED** `qm destroy 9401 --purge` |
|
||
| 2 — host | `r116-images` dir storage at `/mnt/nvme-1tb` | **REMOVED**; space returned (below) |
|
||
| 3 — hub | customer **`sess-e`**, host **`sess-e-5d4427`**, appliance **13** | **GATE-BLOCKED — command recorded below.** The cascade was attempted and **correctly refused: HTTP 409 "Delete refused: host sess-e-5d4427 is ONLINE"**. Deletable once it ages ONLINE→DOWN (>1 h from its last report, `customer_delete.go:220-228`) |
|
||
|
||
**Layer 2, measured:** `felhom-backup` available **928787076 KiB after** vs **928787080 KiB before the
|
||
run** (4 KiB = noise), used back from 17708084 → 4566012 KiB. `local-lvm` **38.84 %** vs 38.83 % — demo-hp's
|
||
own guest, not this run. `r116-images` gone; `qm list` shows only `drill-r50`. **The space came back.**
|
||
|
||
**Secrets:** the break-glass credential and the hub DB copy it came from were `shred -u`'d; the claim code,
|
||
the drill controller password and the session cookie were shredded in the guest and on the box before
|
||
destruction, and the local copies on DooPlex are shredded. The in-guest `shred -u` left 3 files behind
|
||
(reported honestly rather than claimed clean) — they died with the purged disk moments later.
|
||
|
||
`pvesm status` on demo-hp **before** the run, for the layer-2 comparison at teardown:
|
||
|
||
```
|
||
felhom-backup dir active 983379700 4566008 928787080 0.46%
|
||
felhom-pbs pbs active 0 0 0 0.00%
|
||
local dir active 40516856 14961808 23464656 36.93%
|
||
local-lvm lvmthin active 56545280 21956532 34588747 38.83% ← the fence figure, unchanged
|
||
```
|
||
|
||
Teardown commands, recorded now so they cannot be forgotten:
|
||
|
||
```bash
|
||
ssh demo-hp 'qm stop 9401; qm destroy 9401 --purge; pvesm remove r116-images; pvesm status'
|
||
# hub, once the host ages ONLINE→DOWN (customer_delete.go:220-228 refuses only on ONLINE):
|
||
POST /configs/sess-e/delete ack_hosts=1 ack_reset=1 ack_purge=1 confirm_id=sess-e expect_hosts=1
|
||
```
|
||
|
||
**Already clear, and not by this session:** `sess-c` and `sess-d` — both `/customers/<id>` → **HTTP 404**,
|
||
absent from `/configs` and `/hosts`. The operator removed them using the commands the previous report
|
||
recorded. Verified directly rather than inferred.
|
||
|
||
**Fences held:** guest 9201 on both demo boxes untouched · `drill-r50` (VM 300) untouched, `stopped` ·
|
||
neither demo box re-targeted · nothing on `local-lvm` · Peti untouched · v0.115.0 not reverted ·
|
||
the hub DB copy taken for the break-glass credential was `shred -u`'d immediately.
|
||
|
||
## 8. Findings — filed, none fixed
|
||
|
||
- **R-117** — reproduced on real hardware with the read/write probe (`EIO` both directions) while `/disks`
|
||
reports `attached` + `bound_under_parent: true`. Already filed; this run adds the metal-adjacent
|
||
reproduction and the note in §5 about how it colours the reattach leg.
|
||
- **R-118** — the union row's root-filesystem capacity. Its **symptom** is now absent in the target's
|
||
absent state because that row is suppressed; **R-118 is not fixed** and remains open for every other
|
||
registry-only drive (the non-target `adat` row still carries statfs values from its own live mount, so
|
||
the class is unchanged).
|
||
- **R-119 (new) — the claim gate makes the drive-gate legs unreachable to CC, by design, every time.**
|
||
Three sessions have now stopped at the same wall: the controller's storage API is claim-gated, the claim
|
||
code is emailed-only, and `planDriveGates` cannot act until a storage path is registered. This is not a
|
||
defect in the gate — it is correct customer-ownership — but it means **every** future validation of a
|
||
drive-gate behaviour costs an operator email round-trip. Worth a ruling: either a documented
|
||
operator-side test affordance (an operator-scoped claim, explicitly audit-logged), or accept the
|
||
round-trip and put it in the runbook as a **prerequisite step** rather than a mid-run surprise. Filed,
|
||
not designed.
|