Earned during v0.191.1's own live validation. After the customer had been warned, a restart produced ZERO fillwatch lines — equally consistent with 'ran and chose silence' and 'never ran'. Proving the checker was alive needed a deliberate crossing into the critical band. For an edge-triggered check the quiet run IS the healthy steady state, so that ambiguity is permanent rather than rare. Check now logs a per-RUN summary on every run, counting unreadable separately from healthy so a drive that has quietly gone unreadable cannot read as 'all fine'.
This commit is contained in:
@@ -1,5 +1,22 @@
|
|||||||
## Changelog
|
## Changelog
|
||||||
|
|
||||||
|
### v0.191.2 — a quiet fill check now says so (2026-08-02, R-167) — MinAgent: none
|
||||||
|
|
||||||
|
**Earned during v0.191.1's own live validation, which is the strongest evidence it was needed.** After
|
||||||
|
the customer had been warned about `/mnt/sys_drive`, the controller was restarted and produced **zero
|
||||||
|
`fillwatch` log lines** — and that was read, correctly, as unusable: an absent line is equally
|
||||||
|
consistent with *"the check ran and chose silence"* and *"the check never ran"*. Proving the checker
|
||||||
|
was alive required deliberately crossing into the critical band.
|
||||||
|
|
||||||
|
That ambiguity is **permanent, not rare, for this check specifically**: it is edge-triggered, so the
|
||||||
|
HEALTHY STEADY STATE IS A QUIET RUN. Standing rule 3 aimed at the one place it costs most.
|
||||||
|
|
||||||
|
`Check` now logs a per-RUN summary — `checked N filesystem(s), M unreadable/skipped, K
|
||||||
|
notification(s); bands: …` — on every run, healthy or not. **Unreadable is counted separately from
|
||||||
|
healthy**, so a drive that has quietly gone unreadable for weeks cannot read as "all fine". Two tests
|
||||||
|
pin it, including that a second, equally quiet run logs again (the observable is per run, not per
|
||||||
|
change).
|
||||||
|
|
||||||
### v0.191.1 — the fill check also runs at startup (2026-08-02, R-167) — MinAgent: none
|
### v0.191.1 — the fill check also runs at startup (2026-08-02, R-167) — MinAgent: none
|
||||||
|
|
||||||
**Found while live-validating v0.191.0 on guest 9201: the fill check was reachable only on its daily
|
**Found while live-validating v0.191.0 on guest 9201: the fill check was reachable only on its daily
|
||||||
|
|||||||
@@ -195,6 +195,7 @@ func (w *Watcher) Check() error {
|
|||||||
targets := w.targets()
|
targets := w.targets()
|
||||||
seen := make(map[string]bool, len(targets))
|
seen := make(map[string]bool, len(targets))
|
||||||
changed := false
|
changed := false
|
||||||
|
var checked, skipped, emitted int
|
||||||
|
|
||||||
for _, t := range targets {
|
for _, t := range targets {
|
||||||
if t.Path == "" {
|
if t.Path == "" {
|
||||||
@@ -208,8 +209,10 @@ func (w *Watcher) Check() error {
|
|||||||
// backup_target_absent). Reporting it as "full" would be a false alarm with a misleading
|
// backup_target_absent). Reporting it as "full" would be a false alarm with a misleading
|
||||||
// cause, and would tell the customer to delete files that are not the problem.
|
// cause, and would tell the customer to delete files that are not the problem.
|
||||||
w.logger.Printf("[DEBUG] [fillwatch] %s: usage unreadable — skipped (an unreadable filesystem is not a full one)", t.Path)
|
w.logger.Printf("[DEBUG] [fillwatch] %s: usage unreadable — skipped (an unreadable filesystem is not a full one)", t.Path)
|
||||||
|
skipped++
|
||||||
continue
|
continue
|
||||||
}
|
}
|
||||||
|
checked++
|
||||||
prev := w.bands[t.Path]
|
prev := w.bands[t.Path]
|
||||||
next := classify(*u, prev)
|
next := classify(*u, prev)
|
||||||
if next == prev {
|
if next == prev {
|
||||||
@@ -230,6 +233,7 @@ func (w *Watcher) Check() error {
|
|||||||
msg := Message(t, *u, next)
|
msg := Message(t, *u, next)
|
||||||
w.logger.Printf("[WARN] [fillwatch] %s (%q): %s → %s — %.0f%% used, %.1f GB free of %.1f GB; notifying the customer",
|
w.logger.Printf("[WARN] [fillwatch] %s (%q): %s → %s — %.0f%% used, %.1f GB free of %.1f GB; notifying the customer",
|
||||||
t.Path, t.Label, prev, next, u.UsedPercent, u.AvailGB, u.TotalGB)
|
t.Path, t.Label, prev, next, u.UsedPercent, u.AvailGB, u.TotalGB)
|
||||||
|
emitted++
|
||||||
if w.notify != nil {
|
if w.notify != nil {
|
||||||
w.notify(Event{Target: t, Band: next, Usage: *u, Message: msg})
|
w.notify(Event{Target: t, Band: next, Usage: *u, Message: msg})
|
||||||
}
|
}
|
||||||
@@ -244,12 +248,38 @@ func (w *Watcher) Check() error {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// A POSITIVE OBSERVABLE, every run, healthy or not (standing rule 3). Without it a quiet run is
|
||||||
|
// indistinguishable from a checker that never ran — and because this check is edge-triggered, the
|
||||||
|
// HEALTHY steady state IS a quiet run, so the ambiguity is permanent rather than rare. It was hit
|
||||||
|
// for real while live-validating v0.191.1 on 9201: an unchanged band produced zero log lines, and
|
||||||
|
// proving the checker was alive needed a deliberate threshold crossing.
|
||||||
|
w.logger.Printf("[INFO] [fillwatch] checked %d filesystem(s), %d unreadable/skipped, %d notification(s); bands: %s",
|
||||||
|
checked, skipped, emitted, w.bandSummaryLocked())
|
||||||
|
|
||||||
if !changed {
|
if !changed {
|
||||||
return nil
|
return nil
|
||||||
}
|
}
|
||||||
return w.saveLocked()
|
return w.saveLocked()
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// bandSummaryLocked renders the current per-path bands for the run summary, deterministically. Caller
|
||||||
|
// holds w.mu.
|
||||||
|
func (w *Watcher) bandSummaryLocked() string {
|
||||||
|
if len(w.bands) == 0 {
|
||||||
|
return "all ok"
|
||||||
|
}
|
||||||
|
paths := make([]string, 0, len(w.bands))
|
||||||
|
for p := range w.bands {
|
||||||
|
paths = append(paths, p)
|
||||||
|
}
|
||||||
|
sort.Strings(paths)
|
||||||
|
parts := make([]string, 0, len(paths))
|
||||||
|
for _, p := range paths {
|
||||||
|
parts = append(parts, p+"="+w.bands[p].String())
|
||||||
|
}
|
||||||
|
return strings.Join(parts, " ")
|
||||||
|
}
|
||||||
|
|
||||||
// Bands returns a copy of the current per-path state (diagnostics + tests).
|
// Bands returns a copy of the current per-path state (diagnostics + tests).
|
||||||
func (w *Watcher) Bands() map[string]Band {
|
func (w *Watcher) Bands() map[string]Band {
|
||||||
w.mu.Lock()
|
w.mu.Lock()
|
||||||
|
|||||||
@@ -318,3 +318,56 @@ func TestVanishedTargetIsForgotten(t *testing.T) {
|
|||||||
"re-added drive would resume from a stale band instead of warning afresh")
|
"re-added drive would resume from a stale band instead of warning afresh")
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// --- The run summary is the POSITIVE OBSERVABLE ---------------------------------------------------
|
||||||
|
|
||||||
|
// Standing rule 3, aimed at the one place it bites hardest here: this check is edge-triggered, so the
|
||||||
|
// HEALTHY STEADY STATE IS A QUIET RUN. Without a per-run summary line, "the checker ran and correctly
|
||||||
|
// said nothing" and "the checker is dead" produce byte-identical logs, permanently.
|
||||||
|
//
|
||||||
|
// This was hit for real while live-validating v0.191.1 on guest 9201: an unchanged band produced zero
|
||||||
|
// log lines, and proving the checker was alive required a deliberate threshold crossing.
|
||||||
|
func TestEveryRunLogsAPositiveObservable(t *testing.T) {
|
||||||
|
var buf strings.Builder
|
||||||
|
usage := map[string]*Usage{photos.Path: {UsedPercent: 40, AvailGB: 60, TotalGB: 100}}
|
||||||
|
w := New(filepath.Join(t.TempDir(), "s.json"), log.New(&buf, "", 0),
|
||||||
|
func() []Target { return []Target{photos} },
|
||||||
|
func(p string) *Usage { return usage[p] })
|
||||||
|
|
||||||
|
if err := w.Check(); err != nil {
|
||||||
|
t.Fatal(err)
|
||||||
|
}
|
||||||
|
out := buf.String()
|
||||||
|
if !strings.Contains(out, "[fillwatch] checked 1 filesystem(s)") {
|
||||||
|
t.Fatalf("a HEALTHY run logged no summary — a quiet run is then indistinguishable from a "+
|
||||||
|
"checker that never ran, and for an edge-triggered check that is the normal state. Got:\n%s", out)
|
||||||
|
}
|
||||||
|
if !strings.Contains(out, "all ok") {
|
||||||
|
t.Fatalf("the summary does not report the bands. Got:\n%s", out)
|
||||||
|
}
|
||||||
|
|
||||||
|
// And a second, equally quiet run must log again — the observable is per RUN, not per change.
|
||||||
|
buf.Reset()
|
||||||
|
if err := w.Check(); err != nil {
|
||||||
|
t.Fatal(err)
|
||||||
|
}
|
||||||
|
if !strings.Contains(buf.String(), "checked 1 filesystem(s)") {
|
||||||
|
t.Fatalf("the second unchanged run logged nothing. Got:\n%s", buf.String())
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// The summary must distinguish an unreadable filesystem from a healthy one — otherwise a drive that
|
||||||
|
// has silently gone unreadable for weeks reads as "all fine".
|
||||||
|
func TestSummaryCountsUnreadableSeparately(t *testing.T) {
|
||||||
|
var buf strings.Builder
|
||||||
|
w := New(filepath.Join(t.TempDir(), "s.json"), log.New(&buf, "", 0),
|
||||||
|
func() []Target { return []Target{photos} },
|
||||||
|
func(string) *Usage { return nil })
|
||||||
|
if err := w.Check(); err != nil {
|
||||||
|
t.Fatal(err)
|
||||||
|
}
|
||||||
|
if !strings.Contains(buf.String(), "checked 0 filesystem(s), 1 unreadable/skipped") {
|
||||||
|
t.Fatalf("an unreadable filesystem is not distinguished in the summary — it would read as a "+
|
||||||
|
"healthy check. Got:\n%s", buf.String())
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user