Files
felhom.eu/documentation/tests/campaign10-evidence-2026-07-31/RESOLVED-backup-target-pair-went-silent.md
T
admin 405a795e32 Campaign 10: RESOLVED — the backup_target_* silence was transient and self-recovered; SQLITE_BUSY drops are absorbed by retry
Both halves of the disposition were run and neither survived as a finding.

The I1/I1-pair violations cluster at cycles 31-33 and nowhere else across 39
cycles; c34-c39 are clean, so it recovered with no intervention. Final tally I1
37 PASS / 2 VIOLATION, I1-pair 36 PASS / 3 VIOLATION. On the quiesced box one slow
detach with 4 minutes either side produced a perfect pair. And the alarming
false-healthy (mentes bound=False while degraded=false) does not survive
quiescence - I had been reading the two halves at different instants of a detach.
No R-n.

Separately cleared: the hub's SQLITE_BUSY event drops. 7 in 24h including one for
the real customer demo-felhom, and the hub does return 500 with notification
dispatch only after a successful save - so a lost event would be a lost alarm. But
the controller retries 3 times and ZERO events exhausted their attempts; the
07:04:39 drop landed at 07:04:42. Nothing lost. Only cosmetic note: the ERROR line
reads like data loss and is not.
2026-08-02 07:10:49 +02:00

6.8 KiB

OPEN OBSERVATION — the backup_target_* pair stopped firing under rapid detach/reattach cycling

Not filed as a finding yet. The system was still being hammered when this was observed, and a verdict taken on a system mid-abuse is worth little. The disposition below says exactly what would settle it.

What was observed (2026-08-02, run 2b, cycles ~30-32)

Three violations in ~5 minutes, all of the same shape — the expected event simply absent:

04:36:55  I1-pair  mentes return -> got=None sev=None   (want backup_target_restored/info)
04:39:27  I1       mentes absent -> got=None sev=None   (want backup_target_absent/error)
04:41:42  I1-pair  mentes return -> got=None sev=None   (want backup_target_restored/info)

It is NOT hub-side suppression, and NOT a truncated log

The hub pod has 0 restarts over 43 h, so its log is intact, and the controller's own log matches the hub's line for line — the events were never emitted, not emitted-and-dropped:

controller  02:32:34  Event pushed: backup_target_absent (error) — … Mentes …
controller  02:32:38  Event pushed: whole_guest_backup_failed (error) — … felhom-backup tier …
controller  02:35:32  Event pushed: health_degraded (warning) …
controller  02:42:08  Event pushed: storage_disconnected (error) — … Adatok      <-- generic path STILL WORKS
(no backup_target_restored, and no second backup_target_absent, at any point after 02:32:34)

So this is controller-side emission, and it is specific to the backup_target_* pair: the generic storage_disconnected / storage_reconnected pair for the other drive kept firing normally throughout the same window (02:16:02, 02:18:21, 02:27:38, 02:29:35, 02:42:08).

The internally inconsistent state alongside it

Sampled while it was happening:

backup-target:  {"degraded": false, "known": true, "label": "Mentes", "target": "felhom-backup"}
drives:         adatok  bound_under_parent=False  backup_target=None
                mentes  bound_under_parent=False  backup_target=True

mentes is the backup target, reads not bound, and the target state simultaneously reports degraded: false. Those two cannot both be right. If that survives quiescence it is the more serious half of this observation — a false healthy on the backup target, which is I5/I6's failure mode and worse than a missing event.

What is NOT yet established

  • Whether the pair recovers once the cycling stops. The harness detaches and reattaches roughly every two minutes; a real customer does not. Rapid cycling may be outside the design envelope, in which case this is a robustness note rather than a defect.
  • Whether the controller restart at 02:25:37 is implicated. In this controller instance there was 1 backup_target_absent and 0 backup_target_restored; the previous instance emitted complete pairs (02:13:21 restored). That is suggestive, not established.
  • Whether the degraded: false reading was a transient mid-flux sample or a stuck state.

Disposition — how to settle it

After run 2b ends, let the box quiesce with both drives attached, then:

  1. confirm bound_under_parent returns to True for both drives and the target still reads healthy — if it does not, the false-healthy is real and this becomes a finding;
  2. do one slow detach/reattach of mentes with several minutes either side, and check the pair fires. If it does, the observation is "the pair does not survive rapid cycling"; if it does not, the target alarm has silently stopped working, which is severe — an alarm that never fires again after its first firing is worse than no alarm.

Only then does it earn an R-n or a retraction.


RESOLVED (2026-08-02) — transient, self-recovered. NOT filed.

Both halves of the disposition were run. Neither survived.

1. It self-recovered, mid-run, with no intervention

The violations are clustered at cycles 31-33 and nowhere else across 39 cycles:

c28 I1 PASS   c28 I1-pair PASS
c29 I1 PASS   c29 I1-pair PASS
c30 I1 PASS   c30 I1-pair PASS
c31 I1 PASS   c31 I1-pair VIOLATION
c32 I1 VIOLATION   c32 I1-pair VIOLATION
c33 I1 VIOLATION   c33 I1-pair VIOLATION
c34 I1 PASS   c34 I1-pair PASS      <-- recovered on its own
c35..c39 all PASS

Final tally I1 37 PASS / 2 VIOLATION, I1-pair 36 PASS / 3 VIOLATION — a ~3-cycle window inside a 13.5-hour run of sustained 2-minute detach/reattach cycling.

2. A slow cycle on the quiesced box works perfectly

With the run finished and the box quiet, one detach with 4 minutes either side:

07:00:08  backup_target_absent  (error) — A rendszermentés meghajtója nem érhető el: Mentes
07:04:42  backup_target_restored (info) — A rendszermentés meghajtója újra elérhető: Mentes
07:06:37  health_recovered      (info) — Rendszer állapot helyreállt: ok (volt: warn)

3. The "false healthy" was a mid-flux sample, not a stuck state

The alarming pair (mentes bound_under_parent=False and degraded: false) does not survive quiescence. Three minutes after the run ended:

drives:  adatok bound=True          mentes bound=True  backup_target=True
target:  {"degraded": false, "known": true, "label": "Mentes", "target": "felhom-backup"}

Consistent. I was sampling a system mid-detach and reading the two halves at different instants.

Verdict

No R-n. The target alarm does not fire during a narrow window under detach/reattach cycling far faster than any real box sees, and it resumes by itself. Recorded so a future session that sees the same three-cycle cluster knows it was chased to the ground and what settled it.


Also investigated and cleared: the hub's SQLITE_BUSY event drops

Chased during the same test and also not a finding, recorded because the log line is alarming:

[ERROR] Failed to save event from c10-soak: database is locked (5) (SQLITE_BUSY)

7 occurrences in 24 h, including one for the real customer demo-felhom — so it is not a campaign artifact. The hub returns HTTP 500 on the failed save (handler.go:1715) and dispatches notifications only after a successful save, so a genuinely lost event would be a lost alarm.

But the controller retries 3 times, and 0 events exhausted their attempts across the whole run (grep -c "Event push failed after 3 attempts" = 0). The 07:04:39 drop landed 3 seconds later:

07:04:39 [ERROR] Failed to save event … SQLITE_BUSY
07:04:42 [INFO]  Event from c10-soak: backup_target_restored (info) …   <-- same event, retried

Nothing was lost. The one observation worth keeping is cosmetic: [ERROR] Failed to save event reads like data loss and is not — a reader would reasonably conclude an alarm had been dropped. The same contention also skipped monitor ticks (Host OOB, Offsite, restore-test, log-bundle purge), which are periodic and simply run again.