package backup import ( "context" "errors" "strings" "testing" "time" ) // ── R-399 / R-401 — the check tells the operator when it starts costing real time ──────────────── // // The 100% default rests on ONE measurement, on ONE 134 MB store: 39.2 s. It will not stay true. The // notice is what makes that fact reach a person from the product rather than from a customer. // // It is a LOG LINE and nothing else — no hub event, no customer alarm, and it never changes the depth // by itself. TestR399_SlownessRaisesNoHubEvent in cmd/controller pins the first of those; the other // two are pinned here. // slowNoticeFragment is the ASCII-only fingerprint of the notice, chosen so no other line in this // file's logs can match it. const slowNoticeFragment = "R-401: the depth setting needs revisiting" // withSlowThreshold lowers the notice threshold for one test and restores it. // // No test can make a check take five minutes, so the threshold is the seam. Everything else runs // through the real CheckOffboxIntegrity. func withSlowThreshold(t *testing.T, d time.Duration) { t.Helper() prev := integritySlowNoticeThreshold integritySlowNoticeThreshold = d t.Cleanup(func() { integritySlowNoticeThreshold = prev }) } // slowReply makes the `check` call take measurable time so a lowered threshold is genuinely exceeded // rather than merely equalled. func slowReply(out []byte, err error) func(args []string) ([]byte, error) { return okRepo(func(args []string) ([]byte, error) { time.Sleep(3 * time.Millisecond) return out, err }) } // B1 — a slow check warns, and the warning names the duration and the depth. func TestR399_SlowCheckWarns(t *testing.T) { withSlowThreshold(t, time.Millisecond) m, cap := newIntegrityManager(t, slowReply(nil, nil)) res := m.CheckOffboxIntegrity(context.Background()) if !res.OK { t.Fatalf("fixture: this run should pass; got %+v", res) } log := cap.logBuf.String() if !strings.Contains(log, slowNoticeFragment) { t.Fatalf("a check over the threshold produced no notice — the operator would keep spending a "+ "customer's bandwidth every week and hear about it from the customer. Log:\n%s", log) } if !strings.Contains(log, "WARN") { t.Errorf("the notice is not at WARN level:\n%s", log) } // It must name BOTH facts: how long, and how deep. Either alone is unactionable. if !strings.Contains(log, "100%") { t.Errorf("the notice does not name the depth that was slow:\n%s", log) } if !strings.Contains(log, "the check took") { t.Errorf("the notice does not name the duration:\n%s", log) } // And it changes NOTHING by itself. A notice that silently reconfigured the box would be a // behaviour change wearing a notice's clothes. if m.integrityReadDataSubset() != "100%" { t.Error("the notice altered the configured depth — it must only report") } } // B2 — a fast check is silent. A notice that fires every week is not a notice. func TestR399_FastCheckIsSilent(t *testing.T) { withSlowThreshold(t, time.Hour) m, cap := newIntegrityManager(t, okRepo(nil)) m.CheckOffboxIntegrity(context.Background()) if strings.Contains(cap.logBuf.String(), slowNoticeFragment) { t.Fatalf("a check under the threshold warned anyway:\n%s", cap.logBuf.String()) } } // B3 — a SKIP has no duration to judge. func TestR399_SkipNeverWarns(t *testing.T) { withSlowThreshold(t, time.Nanosecond) // every non-zero duration would qualify m, cap := newIntegrityManager(t, okRepo(nil)) if err := m.AcquireRunningForTest(); err != nil { t.Fatalf("fixture: %v", err) } defer m.ReleaseRunningForTest() res := m.CheckOffboxIntegrity(context.Background()) if !res.Skipped { t.Fatalf("fixture: expected a skip, got %+v", res) } if strings.Contains(cap.logBuf.String(), slowNoticeFragment) { t.Fatalf("a skipped check produced a slowness notice — it never ran, so there is no duration "+ "to judge:\n%s", cap.logBuf.String()) } } // B4 — "I could not look" is not "I looked and it was slow". func TestR399_UnreachableNeverWarns(t *testing.T) { withSlowThreshold(t, time.Nanosecond) m, cap := newIntegrityManager(t, func(args []string) ([]byte, error) { time.Sleep(3 * time.Millisecond) return []byte("ssh: connect to host nas.local port 22: Connection refused"), errors.New("exit 1") }) res := m.CheckOffboxIntegrity(context.Background()) if !res.Unreachable { t.Fatalf("fixture: expected unreachable, got %+v", res) } if strings.Contains(cap.logBuf.String(), slowNoticeFragment) { t.Fatalf("an unreachable store produced a slowness notice:\n%s", cap.logBuf.String()) } } // B5 — the notice and the failure verdict are INDEPENDENT facts. Neither suppresses the other. func TestR399_SlowAndFailedProducesBoth(t *testing.T) { withSlowThreshold(t, time.Millisecond) const damaged = "pack 5b1f2c3d: not found in index\nrepository contains errors" m, cap := newIntegrityManager(t, slowReply([]byte(damaged), errFake)) res := m.CheckOffboxIntegrity(context.Background()) if res.OK || res.Unreachable { t.Fatalf("fixture: expected a readable-and-damaged verdict, got %+v", res) } log := cap.logBuf.String() if !strings.Contains(log, "check FAILED") { t.Fatalf("the failure was not reported:\n%s", log) } if !strings.Contains(log, slowNoticeFragment) { t.Fatalf("a slow FAILING check lost its slowness notice — suppressing one fact because the "+ "other fired is how the second fact stops existing:\n%s", log) } }