From 79b6a0974e7ba963747ad88e703f3d8e8a72c2b2 Mon Sep 17 00:00:00 2001 From: rcourtman <8825017+rcourtman@users.noreply.github.com> Date: Wed, 7 Oct 2026 08:57:20 +0100 Subject: [PATCH] Name disk wearout as life remaining and log disk alerts once The Proxmox disk wearout alert read "SSD has less than 10% life remaining (7% wearout)". The number is percent life remaining, so "7% wearout" reads as 7% worn and contradicts the first clause, and the Alerts overview shows that text verbatim. It now reads "SSD life remaining is 7%", the wording host-agent SMART wearout alerts already use. The threshold stays in the alert's Threshold field, which the card and notifications show beside the message; spelling it into the sentence as "below 10%" would be false at exactly 10%, which alerts. CheckDiskHealth also logged a failed disk at error and a worn disk at warn on every evaluation, not when the alert opened. The physical disk poll runs every 5 minutes by default, so one failed disk logged an error 288 times a day for as long as it stayed failed, and mock mode repeated it on every alert tick. Both now log at error or warn only on the evaluation that opens the alert and at debug afterwards. The new log test captures through a hook installed in TestMain: assigning log.Logger inside a test would race with managers that earlier tests leave running. The alerts contract also said wearout recovery needs readings of at least 10%; a 10% reading still matches, so recovery needs readings above it. --- .../v6/internal/subsystems/alerts.md | 24 +++- internal/alerts/alerts_test.go | 111 ++++++++++++++++++ internal/alerts/disk_health.go | 58 ++++++--- 3 files changed, 176 insertions(+), 17 deletions(-) diff --git a/docs/release-control/v6/internal/subsystems/alerts.md b/docs/release-control/v6/internal/subsystems/alerts.md index e00fd188b7..1e96e73aae 100644 --- a/docs/release-control/v6/internal/subsystems/alerts.md +++ b/docs/release-control/v6/internal/subsystems/alerts.md @@ -407,9 +407,10 @@ own inline boundary. A wearout arm keyed on `> 0` silently exempts the single worst reading a disk can publish, which let a spent SSD read critical on the Physical Disks surface while raising no alert at all. -Proxmox wearout recovery requires three consecutive reported readings of at -least 10% remaining life. An absent reading does not prove recovery, and a -new low reading resets the recovery run; until recovery is confirmed the +Proxmox wearout recovery requires three consecutive reported readings above +10% remaining life; a reading of exactly 10% still matches the alert. An +absent reading does not prove recovery, and a new low reading resets the +recovery run; until recovery is confirmed the existing alert retains its low-life value and occurrence. This bounds the resolved-then-refired notification loop when endurance data briefly looks healthy (#2112), while a sustained replacement/corrected reading can still @@ -418,6 +419,23 @@ resolve. `TestCheckDiskHealthWearoutFlappingDoesNotRepeatNotifications` and deduplication and confirmed recovery. This is synthetic source proof, not a claim that the reporter's installed image has been repaired. +The Proxmox wearout value is percent life remaining, so its alert message names +it that way (`SSD life remaining is 7%`), matching the host-agent SMART +`wearout_low` summary; the threshold travels in the alert's `Threshold` field, +which the Alerts card and notifications render beside the message. Calling the +number "wearout" read as 7% worn and contradicted the low-life warning. +`CheckDiskHealth` logs a failed disk at error and a worn disk at warn only on +the evaluation that opens the alert (the canonical `activated` transition); +later polls that still find the disk failed or at or below the wearout +threshold, including mock mode's per-tick evaluation, log at debug. Logging on +every evaluation repeated one failed disk's error on every poll for as long as +it stayed failed. `TestCheckDiskHealthLowWearoutCreatesAlert` pins the message +and `TestCheckDiskHealthLogsAlertOpeningOnce` pins the log-once boundary at the +threshold, including a fresh error when a recovered disk fails again. That test +captures logs through a hook installed in the package `TestMain`, because +assigning `log.Logger` inside a test races with managers earlier tests left +running. + Host SMART counter growth is an event boundary rather than a warning on every historical non-zero value. For an agent-only disk, the first reported UDMA CRC error count establishes an in-memory baseline and raises no alert. A later diff --git a/internal/alerts/alerts_test.go b/internal/alerts/alerts_test.go index 677d046d37..f67cbee911 100644 --- a/internal/alerts/alerts_test.go +++ b/internal/alerts/alerts_test.go @@ -25,6 +25,8 @@ import ( unifiedresources "github.com/rcourtman/pulse-go-rewrite/internal/unifiedresources" "github.com/rcourtman/pulse-go-rewrite/internal/utils" "github.com/rcourtman/pulse-go-rewrite/pkg/proxmox" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" ) // testEnvMu protects concurrent access to PULSE_DATA_DIR during parallel tests. @@ -176,6 +178,61 @@ func newTestManager(t *testing.T) *Manager { return m } +// testLogCapture collects log events for captureTestLogs. TestMain installs +// its hook before any test runs: writing log.Logger inside a test would race +// with goroutines of managers that earlier tests left running. +var testLogCapture struct { + mu sync.Mutex + active bool + lines []capturedLogLine +} + +type capturedLogLine struct { + level zerolog.Level + message string +} + +func TestMain(m *testing.M) { + log.Logger = log.Logger.Hook(zerolog.HookFunc(func(_ *zerolog.Event, level zerolog.Level, message string) { + testLogCapture.mu.Lock() + defer testLogCapture.mu.Unlock() + if testLogCapture.active { + testLogCapture.lines = append(testLogCapture.lines, capturedLogLine{level: level, message: message}) + } + })) + os.Exit(m.Run()) +} + +// captureTestLogs records log events, debug included, until the test ends. +// The returned func counts the events seen so far with a level and message. +func captureTestLogs(t *testing.T) func(zerolog.Level, string) int { + t.Helper() + originalLevel := zerolog.GlobalLevel() + zerolog.SetGlobalLevel(zerolog.DebugLevel) + testLogCapture.mu.Lock() + testLogCapture.active = true + testLogCapture.lines = nil + testLogCapture.mu.Unlock() + t.Cleanup(func() { + testLogCapture.mu.Lock() + testLogCapture.active = false + testLogCapture.lines = nil + testLogCapture.mu.Unlock() + zerolog.SetGlobalLevel(originalLevel) + }) + return func(level zerolog.Level, message string) int { + testLogCapture.mu.Lock() + defer testLogCapture.mu.Unlock() + n := 0 + for _, line := range testLogCapture.lines { + if line.level == level && line.message == message { + n++ + } + } + return n + } +} + func TestAcknowledgePersistsThroughCheckMetric(t *testing.T) { m := newTestManager(t) m.ClearActiveAlerts() @@ -4498,6 +4555,10 @@ func TestCheckDiskHealthLowWearoutCreatesAlert(t *testing.T) { if alert.Threshold != 10.0 { t.Errorf("expected threshold 10.0, got %f", alert.Threshold) } + // Wearout is life remaining: the message must not read as 5% worn. + if want := "SSD life remaining is 5%"; alert.Message != want { + t.Errorf("message = %q, want %q", alert.Message, want) + } if got := alert.Metadata["canonicalAlertKind"]; got != "severity-threshold" { t.Fatalf("canonicalAlertKind = %v, want severity-threshold", got) } @@ -4554,6 +4615,56 @@ func TestCheckDiskHealthWearoutAlertUpdatesOnSubsequentChecks(t *testing.T) { if alert.Value != 6 { t.Errorf("expected value to be updated to 6, got %f", alert.Value) } + if want := "SSD life remaining is 6%"; alert.Message != want { + t.Errorf("message = %q, want %q", alert.Message, want) + } +} + +// The physical-disk poller re-evaluates every disk each cycle (and mock mode +// on every alert tick), so a failed or worn disk must log at error/warn once, +// when its alert opens, and at debug on every later poll. +func TestCheckDiskHealthLogsAlertOpeningOnce(t *testing.T) { + count := captureTestLogs(t) + m := newTestManager(t) + m.ClearActiveAlerts() + + // Exactly at the wearout threshold, which still alerts. + disk := proxmox.Disk{ + DevPath: "/dev/sdf", + Model: "Crucial CT500MX500SSD1", + Serial: "2034E4A1B2C3", + Type: "ssd", + Health: "FAILED", + Wearout: 10, + Size: 500107862016, + } + const polls = 3 + for i := 0; i < polls; i++ { + m.CheckDiskHealth("test-instance", "pve-node1", disk) + } + + if got := count(zerolog.ErrorLevel, "Disk health alert created"); got != 1 { + t.Errorf("error-level health log count after %d polls = %d, want 1", polls, got) + } + if got := count(zerolog.DebugLevel, "Disk health check still failing"); got != polls-1 { + t.Errorf("debug-level health log count after %d polls = %d, want %d", polls, got, polls-1) + } + if got := count(zerolog.WarnLevel, "Disk wearout alert created"); got != 1 { + t.Errorf("warn-level wearout log count after %d polls = %d, want 1", polls, got) + } + if got := count(zerolog.DebugLevel, "Disk life remaining still at or below wearout threshold"); got != polls-1 { + t.Errorf("debug-level wearout log count after %d polls = %d, want %d", polls, got, polls-1) + } + + // A disk that passes and then fails again opens a new alert, which logs + // at error again. + disk.Health = "PASSED" + m.CheckDiskHealth("test-instance", "pve-node1", disk) + disk.Health = "FAILED" + m.CheckDiskHealth("test-instance", "pve-node1", disk) + if got := count(zerolog.ErrorLevel, "Disk health alert created"); got != 2 { + t.Errorf("error-level health log count after the disk failed again = %d, want 2", got) + } } func TestCheckDiskHealthWearoutRecoveryAlertCleared(t *testing.T) { diff --git a/internal/alerts/disk_health.go b/internal/alerts/disk_health.go index 4afe7de5c4..5864403747 100644 --- a/internal/alerts/disk_health.go +++ b/internal/alerts/disk_health.go @@ -26,6 +26,10 @@ func proxmoxDiskAlertMetadata(disk proxmox.Disk) map[string]interface{} { } } +// proxmoxDiskWearoutThreshold is the percent life remaining at or below +// which a Proxmox SSD raises a wearout alert. +const proxmoxDiskWearoutThreshold = 10 + // CheckDiskHealth checks disk health and creates alerts if needed func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { // Create unique alert ID for this disk @@ -84,7 +88,7 @@ func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { metadata := proxmoxDiskAlertMetadata(disk) metadata["disk_health"] = disk.Health - _, _ = m.evaluateCanonicalStatefulAlert(canonicalStatefulAlertParams{ + result, _ := m.evaluateCanonicalStatefulAlert(canonicalStatefulAlertParams{ Spec: spec, Evidence: alertspecs.AlertEvidence{ ObservedAt: time.Now(), @@ -106,12 +110,22 @@ func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { AddToHistory: true, }) - log.Error(). - Str("node", node). - Str("disk", disk.DevPath). - Str("model", disk.Model). - Str("health", disk.Health). - Msg("Disk health alert created") + // Every disk poll re-evaluates a failed disk, so log at error + // only when the alert opens, not on each poll after it. + if diskAlertOpened(result) { + log.Error(). + Str("node", node). + Str("disk", disk.DevPath). + Str("model", disk.Model). + Str("health", disk.Health). + Msg("Disk health alert created") + } else { + log.Debug(). + Str("node", node). + Str("disk", disk.DevPath). + Str("health", disk.Health). + Msg("Disk health check still failing") + } } } else { // Disk is healthy, clear alert if it exists @@ -122,8 +136,11 @@ func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { // cannot prove recovery; 0 from an SSD is a real, fully spent reading, // whereas -1 and rotational 0 are absent evidence. if storagehealth.WearoutReported(disk.Wearout, disk.Type) { - message := fmt.Sprintf("SSD has less than 10%% life remaining (%d%% wearout)", disk.Wearout) - spec, err := buildCanonicalSeverityThresholdSpecWithDirection(canonicalResourceID+"-wearout", canonicalResourceID, resourceName, resourceType, "wearout-remaining", alertspecs.ThresholdDirectionBelow, 10, 0, false) + // Wearout is percent life remaining, not percent worn, so the + // message names it as life remaining, in the host-agent SMART + // wording. The threshold travels in the alert's Threshold field. + message := fmt.Sprintf("SSD life remaining is %d%%", disk.Wearout) + spec, err := buildCanonicalSeverityThresholdSpecWithDirection(canonicalResourceID+"-wearout", canonicalResourceID, resourceName, resourceType, "wearout-remaining", alertspecs.ThresholdDirectionBelow, proxmoxDiskWearoutThreshold, 0, false) if err != nil { log.Warn(). Err(err). @@ -134,7 +151,7 @@ func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { metadata := proxmoxDiskAlertMetadata(disk) metadata["disk_wearout"] = disk.Wearout - _, _ = m.evaluateCanonicalStatefulAlert(canonicalStatefulAlertParams{ + result, _ := m.evaluateCanonicalStatefulAlert(canonicalStatefulAlertParams{ Spec: spec, // Endurance cannot normally improve on the same disk. Require // sustained healthy-looking polls before resolving a worn-disk @@ -156,20 +173,33 @@ func (m *Manager) CheckDiskHealth(instance, node string, disk proxmox.Disk) { Instance: instance, Message: message, Value: float64(disk.Wearout), - Threshold: 10.0, + Threshold: proxmoxDiskWearoutThreshold, Metadata: metadata, AddToRecent: true, AddToHistory: true, }) - if disk.Wearout < 10 { + if diskAlertOpened(result) { log.Warn(). Str("node", node). Str("disk", disk.DevPath). Str("model", disk.Model). - Int("wearout", disk.Wearout). - Msg("Disk wearout alert observed") + Int("lifeRemaining", disk.Wearout). + Msg("Disk wearout alert created") + } else if disk.Wearout <= proxmoxDiskWearoutThreshold { + log.Debug(). + Str("node", node). + Str("disk", disk.DevPath). + Int("lifeRemaining", disk.Wearout). + Msg("Disk life remaining still at or below wearout threshold") } } } } + +// diskAlertOpened reports whether this evaluation opened the alert, as +// opposed to re-evaluating one that is already active, pending, or +// suppressed. +func diskAlertOpened(result alertspecs.EvaluationResult) bool { + return result.Transition != nil && result.Transition.Kind == alertspecs.EvaluationTransitionActivated +}