felhom-controller/controller/internal/backup/r399_slow_notice_test.go

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)
	}
}