diff --git a/grafana-alertcheck/.changeset/v0.1.7.md b/grafana-alertcheck/.changeset/v0.1.7.md new file mode 100644 index 000000000..c18db9b19 --- /dev/null +++ b/grafana-alertcheck/.changeset/v0.1.7.md @@ -0,0 +1,3 @@ +- `watch` now stamps `ready_at` when its first-observation pass completes, and `check` refuses a `from` before it; single-step `check` declares that startup interval as a blind spot and classifies from the pass completion. A window can no longer open inside the startup pass and surface as a spurious `heartbeat_gap` mid-run. +- The detached recorder and the live poller continue the first-observation pass's schedule instead of drawing fresh phases, and a new startup-handoff budget simulates the poller's first cycles and refuses, before the window, any schedule whose first polls would exceed a rule's `maxGap`. +- Budget errors now name rules by title as well as UID (`"Title" (uid)`) and state the minimum `--concurrency` that would fit. diff --git a/grafana-alertcheck/docs/advanced.md b/grafana-alertcheck/docs/advanced.md index 445738268..fa6f0be23 100644 --- a/grafana-alertcheck/docs/advanced.md +++ b/grafana-alertcheck/docs/advanced.md @@ -18,13 +18,22 @@ The scheduler staggers each rule's initial next-due time across its cadence, and ## The check budget -The gate records one observation of every rule up front and checks the schedule against those **measured** latencies (payload sizes varied ~230× across existing rules, so a fixed estimate would be meaningless). It errors at start — before waiting — if any of three conditions hold: +The gate records one observation of every rule up front and checks the schedule against those **measured** latencies (payload sizes varied ~230× across existing rules, so a fixed estimate would be meaningless). It errors at start — before waiting — if any of four conditions hold: - **Utilization** — total request rate exceeds `--concurrency`. - **Per-rule** — one rule's request can't fit its own cadence. - **Burst bound** — the slowest request exceeds the fleet's tightest cadence, which can open a mid-run gap. +- **Startup handoff** — draining the first-observation pass's backlog at `--concurrency` would leave some rule unpolled past its own `maxGap`. A rule the pass observed early is seeded overdue, and a tight rule observed late can queue behind every rule due before it. The gate simulates the poller's first cycles from the recorded observation times and measured latencies — each wake takes every rule due at that instant, polls the batch at `--concurrency`, and wakes again when it ends — and refuses if any rule's first poll would land past its `maxGap`. Steady-state utilization cannot see this — a long pass at low concurrency is exactly the case it passes. -The error names the three levers only: raise `--concurrency`, raise `--poll-interval`, or watch fewer alerts. It never prescribes a single interval. +The error names only the levers that can fix it: the minimum `--concurrency` when the schedule is concurrency-bound, and `--poll-interval` or a smaller alert set for single-request shapes concurrency cannot shorten. It never prescribes a single interval. + +## The startup pass and `ready_at` + +Before detaching, `watch` observes every non-paused rule once, sequentially bounded by `--concurrency`. With many alerts and a low concurrency that pass takes real time (120 rules at ~230 ms each and the default concurrency of 1 is ~27 s). The header's `ready_at` stamps the moment the pass completed, and `check` refuses a `from` before it: a window opening inside the pass names observations that do not exist yet, and the earliest rules have no next poll until the detached recorder starts. This is a startup validation, checked from the immutable header before the wait, so a `from` emitted before `watch` returns fails immediately with a named reason instead of surfacing as a heartbeat gap mid-window. Emit `from` only after `watch` returns. + +The detached recorder then continues the schedule the first observations were on (each rule's next poll is one cadence after its last recorded observation) rather than drawing fresh phases, so the handoff adds no extra up-to-one-cadence delay to the rules the pass observed first. Continuing the schedule is necessary but not sufficient: the startup-handoff budget above proves the backlog can actually be drained before any rule's `maxGap`, and refuses the run at startup when it cannot. + +Single-step `check` runs the same pass itself. It cannot watch before it started, so a `from` inside the pass is a declared blind interval: the run warns, classifies from the pass completion, and the live poller continues the pass's schedule. It never classifies a window that opens before every rule has been observed. ## Why the gate never queries state history diff --git a/grafana-alertcheck/docs/architecture.md b/grafana-alertcheck/docs/architecture.md index 092d68c62..1636f7c54 100644 --- a/grafana-alertcheck/docs/architecture.md +++ b/grafana-alertcheck/docs/architecture.md @@ -55,7 +55,7 @@ This, plus the declared supported range (Grafana >= 13.0.0, < 14.0.0), is how a `watch` detaches a background recorder so observation survives the step boundary: -1. Parent resolves the alert set (names or labels), writes the header, observes every non-paused rule once, checks the budget. +1. Parent resolves the alert set (names or labels), observes every non-paused rule once, checks the budget, then writes the header — whose `ReadyAt` stamps the pass completion — and the observations. `ReadyAt` is what `check` uses to refuse a `from` that falls inside the pass. 2. Parent re-execs itself as the child (`--daemon-child`) under a new session/process group, stdout/stderr to the daemon log. 3. Child re-reads the header, reopens the log `O_APPEND`, takes the exclusive `flock`, and writes one readiness byte on `--ready-fd`. 4. Parent writes the pidfile **after** the readiness report, then returns. diff --git a/grafana-alertcheck/docs/index.md b/grafana-alertcheck/docs/index.md index d93630cbb..b5acc57e6 100644 --- a/grafana-alertcheck/docs/index.md +++ b/grafana-alertcheck/docs/index.md @@ -60,7 +60,7 @@ Skip the recorder and observe the window inline, from inside `check` itself: grafana-alertcheck check --alerts alerts.txt --to "$finished_at" ``` -In single-step mode the window starts at `check`'s first observation; if you give no `--from`, the interval before that first observation is declared as a blind spot with a warning (not an error). +In single-step mode the window starts at `check`'s first-observation pass completion; if you give no `--from`, or a `--from` inside the pass, the interval before that point is declared as a blind spot with a warning (not an error). ## Exit codes diff --git a/grafana-alertcheck/docs/reference/cli.md b/grafana-alertcheck/docs/reference/cli.md index 947ec7120..07c15602d 100644 --- a/grafana-alertcheck/docs/reference/cli.md +++ b/grafana-alertcheck/docs/reference/cli.md @@ -43,7 +43,7 @@ grafana-alertcheck watch --out [--pidfile F] [--daemon-log F] \ | `--concurrency` | `1` | Max concurrent requests to Grafana | | `--until` | run until signalled | Optional hard stop | -`watch` writes the header, observes every non-paused rule once, checks the budget, then detaches a background recorder and returns. Recording is **unfiltered** — there is no `--states` here, so the same log can be re-classified later under different `--states` without re-recording. +`watch` observes every non-paused rule once, checks the budget, writes the header (with `ready_at` stamped once the observation pass completes) and those observations, then detaches a background recorder and returns. Recording is **unfiltered** — there is no `--states` here, so the same log can be re-classified later under different `--states` without re-recording. ## `stop` — reap the recorder @@ -92,7 +92,7 @@ grafana-alertcheck check [--in ] [--pidfile F] --from RFC3339 --to RFC3339 By default `check` **exits early** on a failure that cannot become a pass: a post-`from` bad onset, or an inability (a heartbeat gap, a sustained `health=error`, a stale evaluation, an in-window pause, an absent rule). This is a latency optimization, not a weaker gate — it never exits `0` early. The one observable difference is that an early exit can report `1` where a full run would have discovered an inability later and reported `2`. `--no-fail-fast` always waits for `to + transitionGrace` and the full coverage proof; the `Result` then carries no `terminated_early` marker. With early exit the JSON result includes `terminated_early` naming the rule, kind, reason and time. -`--from` and `--to` are RFC3339 with an explicit offset and must come from your work — `from` from the deploy step, `to` from the step that finishes. In recorder mode an absent `--from` is a hard error; in single-step mode it falls back (with a warning) to the start of the step. +`--from` and `--to` are RFC3339 with an explicit offset and must come from your work — `from` from the deploy step, `to` from the step that finishes. In recorder mode an absent `--from` is a hard error, and a `from` before the recording's first-observation pass is refused; in single-step mode an absent `from`, or one inside `check`'s own first-observation pass, is a declared blind interval — the window is classified from the pass completion, with a warning. ## Naming alerts diff --git a/grafana-alertcheck/docs/reference/log-format.md b/grafana-alertcheck/docs/reference/log-format.md index 0bf1830af..74694c8d7 100644 --- a/grafana-alertcheck/docs/reference/log-format.md +++ b/grafana-alertcheck/docs/reference/log-format.md @@ -31,6 +31,7 @@ The header must be line 1, appear once, and carry `schema_version` `1` (any othe "url": "https://grafana.example.com", "grafana_version": "13.1.0", "started_at": "2026-09-07T10:00:00Z", + "ready_at": "2026-09-07T10:00:27Z", "rules": [ { "uid": "rule0000001", @@ -49,6 +50,7 @@ The header must be line 1, appear once, and carry `schema_version` `1` (any othe ``` - `url` and `rules` are the log's identity — `check` validates them against the current environment and a fresh ruler read. +- `started_at` is when the recording opened; `ready_at` is when the first-observation pass completed and every watched, non-paused rule had been observed once. The pass is sequential, so `check` refuses a `from` before `ready_at` (a window opening inside the pass would rest on observations that do not exist). `ready_at` is absent on logs written before the field existed; `check` then falls back to `started_at`. - `is_paused` records the pause state at record start (the moment `paused` means). - `poll_every_seconds` is the cadence the recording **actually used** (after any `--poll-interval` override). `check` derives `maxGap` from it, never from `interval_seconds`. - `for_seconds`, `interval_seconds`, `no_data_state`, `exec_err_state` are forensic only — `check` re-resolves definitions and never reads them back. diff --git a/grafana-alertcheck/internal/gate/check.go b/grafana-alertcheck/internal/gate/check.go index f04fa0f25..43e03d138 100644 --- a/grafana-alertcheck/internal/gate/check.go +++ b/grafana-alertcheck/internal/gate/check.go @@ -54,9 +54,9 @@ type Config struct { NoFailFast bool // From is the moment the deploy finished and To is the end of the work. - // They are different moments and both come from the work. In recorder mode - // an absent From is a hard error; in single-step mode it falls back to the - // start of this step, with a blind-interval warning. + // In recorder mode an absent From is a hard error; in single-step mode it + // falls back to the start of this step, and a From before the + // first-observation pass completes is a declared blind interval. From, To time.Time // Log is the path of a recording made by watch; "" selects single-step @@ -165,7 +165,7 @@ func (cfg Config) validate() error { return errors.New("check: no `from` in recorder mode: the deploy step must emit a completion timestamp") case from.IsZero(): // Single-step only. The caller sees the resulting blind interval named - // exactly, once the first observation has fixed its end. + // exactly, once the first-observation pass has fixed its end. from = now } @@ -245,6 +245,14 @@ func check(ctx context.Context, cfg Config, src Source) (Result, error) { return Result{}, fmt.Errorf("check: `from` %s is before recording started at %s", from.Format(time.RFC3339), earlyHdr.StartedAt.Format(time.RFC3339)) } + // The pass is sequential, so a `from` inside it names a window + // whose earliest rules were never watched. Knowable from the + // immutable header, so it fails before the wait. + if from.Truncate(time.Second).Before(earlyHdr.ReadyAt.Truncate(time.Second)) { + return Result{}, fmt.Errorf( + "check: `from` %s is inside the recorder's initial observation pass, which completed at %s; emit `from` after `watch` returns (watch observes every watched rule before returning)", + from.Format(time.RFC3339), earlyHdr.ReadyAt.Format(time.RFC3339)) + } } } else { resolved, notes, err = resolveAlertSet(allDefs, cfg.namedAlerts(), cfg.IncludeLabels, cfg.ExcludeLabels, cfg.Folder) @@ -308,12 +316,20 @@ func check(ctx context.Context, cfg Config, src Source) (Result, error) { // proves that interval, not this timestamp. startedAt := cfg.Clock.Now() active := activeRules(resolved) + activeRT := activeTimingsOf(active, rt) var measured map[string]time.Duration initial, measured, err = firstObservations(ctx, src, active, reducer, cfg.Concurrency, cfg.Notes) if err != nil { return Result{}, err } - if err := CheckBudget(activeTimingsOf(active, rt), measured, cfg.Concurrency); err != nil { + // The pass is over; the live poller will start from this instant, so + // both budget checks judge the schedule it will actually run. + readyAt := cfg.Clock.Now() + if err := CheckBudget(activeRT, measured, cfg.Concurrency); err != nil { + return Result{}, err + } + // The clamp below is exact, so the window cannot open before readyAt. + if err := CheckStartupHandoff(activeRT, measured, initial, readyAt, readyAt, cfg.Concurrency); err != nil { return Result{}, err } @@ -321,22 +337,35 @@ func check(ctx context.Context, cfg Config, src Source) (Result, error) { // shell builds the Header and later stamps the sentinel itself, so the // sentinel and from-bounds coverage checks run exactly as they do over // a recording and no mode flag ever reaches proveCoverage or decide. + // + // ReadyAt is the pass completion: single-step cannot watch before it + // started, so a `from` inside the pass is declared blind and the window + // is classified from ReadyAt. header = Header{ SchemaVersion: LogSchemaVersion, URL: cfg.URL, GrafanaVersion: version, StartedAt: startedAt, + ReadyAt: readyAt, Rules: loggedRules(resolved, rt), } - if from.Before(startedAt) { + if from.Before(readyAt) { // The declared blind interval: in single-step mode this is a // warning and a pass, and ONLY here. Recorder mode keeps the // from-bounds coverage check strict, because there the recorder // was supposed to be watching and the gap means it was not. - fmt.Fprintf(cfg.Notes, "warning: cannot see [%s, %s) — %s before the first observation; the window is classified from %s\n", - from.Format(time.RFC3339), startedAt.Format(time.RFC3339), - startedAt.Sub(from).Round(time.Second), startedAt.Format(time.RFC3339)) - from = startedAt + // + // A clamp past `to` leaves no requested window to classify (and an + // inverted window can prove nothing), so fail closed instead. + if !readyAt.Before(cfg.To) { + return Result{}, fmt.Errorf( + "check: the first-observation pass completed at %s, at or after `to` %s: no window remains to classify", + readyAt.Format(time.RFC3339), cfg.To.Format(time.RFC3339)) + } + fmt.Fprintf(cfg.Notes, "warning: cannot see [%s, %s) — %s before the first observation pass completed; the window is classified from %s\n", + from.Format(time.RFC3339), readyAt.Format(time.RFC3339), + readyAt.Sub(from).Round(time.Second), readyAt.Format(time.RFC3339)) + from = readyAt } } @@ -369,7 +398,7 @@ func check(ctx context.Context, cfg Config, src Source) (Result, error) { guard terminalCheck ) if !logHasHdr { - poller = newLivePoller(src, reducer, activeRules(resolved), rt, cfg.Concurrency, cfg.Clock.Now()) + poller = newLivePoller(src, reducer, activeRules(resolved), rt, cfg.Concurrency, cfg.Clock.Now(), initial) } failFast := !cfg.NoFailFast if failFast { @@ -539,8 +568,11 @@ type livePoller struct { concurrency int } +// newLivePoller builds single-step mode's collection engine. seed, when +// present, is the measurement pass's observations: the poller continues their +// schedule instead of drawing fresh phases. nil falls back to the fresh stagger. func newLivePoller(src Source, reducer *Reducer, active []Definition, rt map[string]RuleTimings, - concurrency int, now time.Time) *livePoller { + concurrency int, now time.Time, seed []Poll) *livePoller { titles := make(map[string]string, len(active)) cadence := make(map[string]time.Duration, len(active)) @@ -548,10 +580,14 @@ func newLivePoller(src Source, reducer *Reducer, active []Definition, rt map[str titles[d.UID] = d.Title cadence[d.UID] = rt[d.UID].pollEvery } + sched := NewScheduler(cadence, now) + if len(seed) > 0 { + sched = NewSchedulerFromPolls(cadence, seed, now) + } return &livePoller{ src: src, reducer: reducer, - sched: NewScheduler(cadence, now), + sched: sched, titles: titles, concurrency: concurrency, } diff --git a/grafana-alertcheck/internal/gate/check_test.go b/grafana-alertcheck/internal/gate/check_test.go index d14ccf139..210a427a4 100644 --- a/grafana-alertcheck/internal/gate/check_test.go +++ b/grafana-alertcheck/internal/gate/check_test.go @@ -572,6 +572,75 @@ func TestCheckSingleStepFromBeforeFirstObservationWarnsAndPasses(t *testing.T) { require.True(t, res.From.Equal(testNow)) } +// A `from` inside single-step's measurement pass is a declared blind interval: +// the earliest rules have no observation yet, so the window is classified from +// the pass completion instead of opening inside it. +func TestCheckSingleStepFromInsideTheMeasurementPassIsClampedToThePassCompletion(t *testing.T) { + clock := newVirtualClock(testNow) + cfg := baseConfig(t, clock) + cfg.From = testNow + cfg.To = testNow.Add(30 * time.Second) + + // A 10s rule: pollEvery 5s, maxGap 10s. The 12s pass is longer than its + // maxGap, so without the clamp its first in-window poll would already be a + // heartbeat gap — exactly the live-mode incident's shape. + src := newCheckSource(func(_ string, call int) (Observation, error) { + if call == 1 { + clock.Advance(12 * time.Second) // the pass takes real time + } + return healthyObservation(clock.Now()), nil + }) + src.defs = []Definition{{ + UID: checkUID, Title: checkTitle, Folder: "F", Group: "G", + IntervalSeconds: 10, NoDataState: "OK", ExecErrState: "OK", + Kind: KindGrafanaManaged, + }} + + res, err := check(context.Background(), cfg, src) + require.NoError(t, err) + notes := notesOf(cfg) + require.Contains(t, notes, "cannot see [") + require.Contains(t, notes, "first observation pass completed") + require.True(t, res.From.Equal(testNow.Add(12*time.Second)), + "the classified window must start at the pass completion, not inside the pass") + require.False(t, res.Coverage[checkUID].Unobservable, + "clamping must not leave the first rule's heartbeat gap inside the window") + require.LessOrEqual(t, res.Coverage[checkUID].LargestGap, 5*time.Second, + "only the rule's own 5s cadence may remain between the clamped open and the polls") +} + +// The measurement pass can outlast the requested window when `--to` is close +// ahead; clamping `from` past `to` would invert the window and prove nothing, +// so check must fail closed instead. +func TestCheckSingleStepPassOutlastingTheWindowFailsClosed(t *testing.T) { + clock := newVirtualClock(testNow) + cfg := baseConfig(t, clock) + cfg.To = testNow.Add(time.Second) + + src := newCheckSource(func(_ string, _ int) (Observation, error) { + clock.Advance(5 * time.Second) // the pass runs past `to` + return healthyObservation(clock.Now()), nil + }) + + _, err := check(context.Background(), cfg, src) + require.Error(t, err) + require.Contains(t, err.Error(), "no window remains") +} + +// The live poller continues the measurement pass's schedule: an overdue rule is +// due immediately instead of waiting out a fresh stagger. +func TestNewLivePollerContinuesTheMeasurementPass(t *testing.T) { + seed := []Poll{{RuleUID: checkUID, GrafanaNow: testNow.Add(-90 * time.Second), Found: true}} + p := newLivePoller(nil, NewReducer(), + []Definition{{UID: checkUID, Title: checkTitle}}, + map[string]RuleTimings{checkUID: {pollEvery: 30 * time.Second}}, + 1, testNow, seed) + + require.Equal(t, testNow.Add(-60*time.Second), p.sched.next[checkUID], + "the live poller must continue the measurement pass, not re-stagger") + require.Contains(t, p.sched.Due(testNow), checkUID) +} + // The failure limit was exceeded. The measurement pass succeeds and the // collection loop then hits a terminal failure, so this exercises the path a // live run really takes. @@ -644,11 +713,57 @@ func TestCheckSingleStepRefusesAScheduleThatDoesNotFit(t *testing.T) { _, err := check(context.Background(), cfg, src) require.Error(t, err, "the budget check to refuse the schedule") - for _, want := range []string{"raising concurrency", "raising poll-interval", "watching fewer alerts"} { + for _, want := range []string{"raising --concurrency to at least 2", "raising poll-interval", "watching fewer alerts"} { require.Contains(t, err.Error(), want) } } +// A tight rule observed late queues behind every rule due before it; if that +// backlog cannot drain within its maxGap, check must refuse at startup rather +// than discover the gap mid-window. +func TestCheckSingleStepRefusesAnUnsafeStartupHandoff(t *testing.T) { + clock := newFakeClock(testNow) + cfg := baseConfig(t, clock) + cfg.Concurrency = 3 // enough for the steady-state utilization, not for the startup backlog + + const slack = 20 + defs := make([]Definition, 0, slack+1) + alerts := make([]string, 0, slack+1) + observed := make(map[string]time.Time, slack+1) + for i := range slack { + uid := fmt.Sprintf("slack%02d", i) + defs = append(defs, Definition{ + UID: uid, Title: uid, IntervalSeconds: 40, NoDataState: "OK", ExecErrState: "OK", + Kind: KindGrafanaManaged, + }) + alerts = append(alerts, "uid:"+uid) + observed[uid] = testNow.Add(time.Duration(i) * 2 * time.Second) + } + defs = append(defs, Definition{ + UID: checkUID, Title: checkTitle, IntervalSeconds: 8, NoDataState: "OK", ExecErrState: "OK", + Kind: KindGrafanaManaged, + }) + alerts = append(alerts, "uid:"+checkUID) + observed[checkTitle] = testNow.Add(40 * time.Second) // observed last + + cfg.Alerts = alerts + src := newCheckSource(func(title string, _ int) (Observation, error) { + at := observed[title] + if at.After(clock.Now()) { + clock.Advance(at.Sub(clock.Now())) + } + obs := healthyObservation(at) + obs.Latency = 2 * time.Second + return obs, nil + }) + src.defs = defs + + _, err := check(context.Background(), cfg, src) + require.Error(t, err, "the startup handoff to refuse the schedule") + require.Contains(t, err.Error(), "startup handoff") + assertBudgetMessage(t, err.Error()) +} + // --------------------------------------------------------------------------- // Recorder mode // --------------------------------------------------------------------------- @@ -667,6 +782,7 @@ func recordedLog(t *testing.T, dir string, url string, startedAt, start, end, se URL: url, GrafanaVersion: "13.1.0", StartedAt: startedAt, + ReadyAt: startedAt, Rules: []LoggedRule{{ UID: checkUID, Title: checkTitle, Folder: "F", Group: "G", IntervalSeconds: 60, NoDataState: "OK", ExecErrState: "OK", @@ -891,6 +1007,35 @@ func TestCheckRecorderModeFromSameSecondAsStartedAtPasses(t *testing.T) { require.Equal(t, OutcomeHealthy, res.Verdicts[0].Outcome) } +// A `from` between StartedAt and ReadyAt sits inside the recorder's sequential +// first-observation pass, so the rules observed first have no poll in the +// window's opening stretch. ReadyAt is in the immutable header, so this fails +// before the wait. +func TestCheckRecorderModeRefusesFromInsideTheInitialObservationPass(t *testing.T) { + dir := t.TempDir() + windowEnd := testNow.Add(5*time.Minute + checkGrace) + path := filepath.Join(dir, "log.jsonl") + w, err := NewWriter(path, newFakeClock(windowEnd.Add(30*time.Second))) + require.NoError(t, err) + require.NoError(t, w.WriteHeader(Header{ + URL: "https://grafana.example.com", GrafanaVersion: "13.1.0", + StartedAt: testNow.Add(-time.Minute), + ReadyAt: testNow.Add(30 * time.Second), + Rules: []LoggedRule{{ + UID: checkUID, Title: checkTitle, IntervalSeconds: 60, + PollEverySeconds: checkPollEvery.Seconds(), + }}, + })) + require.NoError(t, w.Stop()) + + clock := newVirtualClock(testNow) + cfg := recorderConfig(t, clock, path) // From = testNow, inside [StartedAt, ReadyAt) + _, err = check(context.Background(), cfg, newCheckSource(nil)) + require.Error(t, err) + require.Contains(t, err.Error(), "initial observation pass") + require.True(t, clock.Now().Equal(testNow), "it must fail before the wait") +} + // The coverage proof failed: a hole in the middle of the recording is not // saved by healthy data at both ends. func TestCheckFailClosedOnCoverageGap(t *testing.T) { diff --git a/grafana-alertcheck/internal/gate/coverage.go b/grafana-alertcheck/internal/gate/coverage.go index 0b69abc32..977c45c9e 100644 --- a/grafana-alertcheck/internal/gate/coverage.go +++ b/grafana-alertcheck/internal/gate/coverage.go @@ -10,7 +10,7 @@ const keepLastReason = "KeepLast" // Two things this file leaves to its callers: the "from too far ahead" bound is // Config.validate's once-per-run input validation (check 2 owns only the -// "from < StartedAt" half), and a rule paused at the window open never reaches +// "from < readyAt" half), and a rule paused at the window open never reaches // proveCoverage — decide reads `skipped` from Header.pausedAtStart first, so a // paused rule's zero polls read as skipped, not as one large heartbeat gap. @@ -85,19 +85,23 @@ func proveCoverage(h Header, polls []Poll, sentinel *time.Time, t RuleTimings, d sentinel.Format(time.RFC3339), windowEnd.Format(time.RFC3339))) } - // Check 2 — from bounds: from < StartedAt makes coverage unprovable, no - // matter how healthy the polls that DO exist look. Both are runner-domain - // clock reads (the recorder's own Clock.Now()), so no cross-domain - // translation applies here. The comparison is at whole-second granularity: - // `from` is supplied at second precision (--from RFC3339) while StartedAt - // carries the recorder's sub-second clock stamp, so an operator naming the - // exact second the recording opened must not be judged early for the - // sub-second sliver inside that same second. The other half of the bound — - // from too far ahead of the runner's clock — is Check's input validation, - // once per run rather than per rule. - if from.Truncate(time.Second).Before(h.StartedAt.Truncate(time.Second)) { - fail(ReasonFromBeforeRecord, fmt.Sprintf( - "requested from %s is before recording started at %s", from.Format(time.RFC3339Nano), h.StartedAt.Format(time.RFC3339Nano))) + // Check 2 — from bounds: from < the recording's readiness makes coverage + // unprovable, no matter how healthy the polls that DO exist look. The + // authority is readyAt() — ReadyAt when the log records it, StartedAt + // otherwise — because the first-observation pass is sequential: a `from` + // inside it names a window in which the earliest rules were never observed. + // Both are runner-domain clock reads, so no cross-domain translation + // applies. The comparison is at whole-second granularity, matching `from`'s + // second precision. The other half of the bound — from too far ahead of the + // runner's clock — is Check's input validation, once per run not per rule. + if readyAt := h.readyAt(); from.Truncate(time.Second).Before(readyAt.Truncate(time.Second)) { + note := fmt.Sprintf("requested from %s is before recording started at %s", + from.Format(time.RFC3339Nano), readyAt.Format(time.RFC3339Nano)) + if !h.ReadyAt.IsZero() { + note = fmt.Sprintf("requested from %s is before the recorder was ready at %s (the initial observation pass had not completed)", + from.Format(time.RFC3339Nano), readyAt.Format(time.RFC3339Nano)) + } + fail(ReasonFromBeforeRecord, note) } // Filtered once and threaded through every remaining check. diff --git a/grafana-alertcheck/internal/gate/coverage_test.go b/grafana-alertcheck/internal/gate/coverage_test.go index 226b46243..0a6283884 100644 --- a/grafana-alertcheck/internal/gate/coverage_test.go +++ b/grafana-alertcheck/internal/gate/coverage_test.go @@ -183,6 +183,48 @@ func TestProveCoverage_FromSubSecondEarlierAcrossSecondBoundaryIsUnobservable(t require.False(t, res.Proved) } +// ReadyAt, not StartedAt, is the from-bounds authority: a `from` before the +// first-observation pass completed names a window the pass cannot cover. +func TestProveCoverage_FromBeforeReadyAtIsUnobservable(t *testing.T) { + from := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + to := from.Add(10 * time.Minute) + rt := newRuleTimings(30*time.Second, 60) + def := Definition{UID: "r1", Title: "R1"} + + var polls []Poll + for ts := from.Add(30 * time.Second); !ts.After(to); ts = ts.Add(30 * time.Second) { + polls = append(polls, Poll{RuleUID: "r1", GrafanaNow: ts, Found: true, Health: "ok", State: "inactive", LastEvaluation: ts}) + } + sentinel := to + + res := proveCoverage(Header{StartedAt: from.Add(-time.Minute), ReadyAt: from.Add(30 * time.Second)}, + polls, &sentinel, rt, def, from, to, 0) + require.Equal(t, ReasonFromBeforeRecord, res.Reason) + require.True(t, res.Unobservable) + require.False(t, res.Proved) + require.Contains(t, strings.Join(res.Notes, "; "), "initial observation pass") +} + +// The whole-second tolerance applies to ReadyAt too: a `from` in the same +// second the pass completed is not judged early. +func TestProveCoverage_FromSameSecondAsReadyAtIsProved(t *testing.T) { + from := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + to := from.Add(10 * time.Minute) + rt := newRuleTimings(30*time.Second, 60) + def := Definition{UID: "r1", Title: "R1"} + + var polls []Poll + for ts := from; !ts.After(to); ts = ts.Add(30 * time.Second) { + polls = append(polls, Poll{RuleUID: "r1", GrafanaNow: ts, Found: true, Health: "ok", State: "inactive", LastEvaluation: ts}) + } + sentinel := to + + res := proveCoverage(Header{StartedAt: from.Add(-time.Minute), ReadyAt: from.Add(500 * time.Millisecond)}, + polls, &sentinel, rt, def, from, to, 0) + require.True(t, res.Proved) + require.False(t, res.Unobservable) +} + // --- Check 3: heartbeat continuity --- // The core heartbeat regression: data at both ends with a hole between is not diff --git a/grafana-alertcheck/internal/gate/handoff.go b/grafana-alertcheck/internal/gate/handoff.go new file mode 100644 index 000000000..d5a0ff0db --- /dev/null +++ b/grafana-alertcheck/internal/gate/handoff.go @@ -0,0 +1,172 @@ +package gate + +import ( + "container/heap" + "fmt" + "sort" + "strings" + "time" +) + +// CheckStartupHandoff proves the first poll after the measurement pass arrives +// before each rule's maxGap — a transient the steady-state budget cannot see. +// It simulates the poller's first cycles and fails on any first poll past it. +// windowOpen is the earliest instant the classification window can open. +func CheckStartupHandoff(t map[string]RuleTimings, measured map[string]time.Duration, first []Poll, readyAt, windowOpen time.Time, concurrency int) error { + if len(t) == 0 { + return nil + } + if concurrency < 1 { + concurrency = 1 + } + problems, err := handoffProblems(t, measured, first, readyAt, windowOpen, concurrency) + if err != nil { + return err + } + if len(problems) == 0 { + return nil + } + + var b strings.Builder + fmt.Fprintf(&b, "startup handoff does not fit at concurrency %d:\n", concurrency) + const maxListed = 5 + for i, p := range problems { + if i == maxListed { + fmt.Fprintf(&b, " - ... and %d more\n", len(problems)-maxListed) + break + } + fmt.Fprintf(&b, " - %s\n", p) + } + if minC := minHandoffConcurrency(t, measured, first, readyAt, windowOpen, concurrency, len(t)); minC > concurrency { + fmt.Fprintf(&b, "fix by: raising --concurrency to at least %d (currently %d), raising poll-interval, or watching fewer alerts", + minC, concurrency) + } else { + b.WriteString("fix by: raising poll-interval or watching fewer alerts") + } + return fmt.Errorf("%s", b.String()) +} + +// handoffProblems returns one message per rule whose simulated first poll is late. +func handoffProblems(t map[string]RuleTimings, measured map[string]time.Duration, first []Poll, readyAt, windowOpen time.Time, concurrency int) ([]string, error) { + type job struct { + uid string + title string + due time.Time + latency time.Duration + bound time.Duration + maxGap time.Duration + pollEvery time.Duration + } + jobs := make([]job, 0, len(t)) + for _, p := range first { + rt, ok := t[p.RuleUID] + if !ok { + continue + } + m, ok := measured[p.RuleUID] + if !ok { + return nil, fmt.Errorf("startup handoff: rule %s was never measured", ruleLabel(rt.title, p.RuleUID)) + } + jobs = append(jobs, job{ + uid: p.RuleUID, + title: rt.title, + due: runnerTime(p, p.GrafanaNow).Add(rt.pollEvery), + latency: m, + bound: p.SkewBound(), + maxGap: rt.maxGap, + pollEvery: rt.pollEvery, + }) + } + if len(jobs) != len(t) { + return nil, fmt.Errorf("startup handoff: %d of %d rule(s) have a first observation", len(jobs), len(t)) + } + // Matches Scheduler.Due: earliest-due first, ties by tightest cadence, then uid. + sort.Slice(jobs, func(i, j int) bool { + if !jobs[i].due.Equal(jobs[j].due) { + return jobs[i].due.Before(jobs[j].due) + } + if jobs[i].pollEvery != jobs[j].pollEvery { + return jobs[i].pollEvery < jobs[j].pollEvery + } + return jobs[i].uid < jobs[j].uid + }) + + var problems []string + now := readyAt + for i := 0; i < len(jobs); { + if jobs[i].due.After(now) { + now = jobs[i].due + } + free := newTimeHeap(concurrency, now) + batchEnd := now + j := i + for ; j < len(jobs) && !jobs[j].due.After(now); j++ { + start := free.pop() + finish := start.Add(jobs[j].latency) + // `bound` keeps a boundary-adjacent window open on the fail-closed side. + if gap := finish.Sub(windowOpen) + jobs[j].bound; gap > jobs[j].maxGap { + problems = append(problems, fmt.Sprintf( + "rule %s: first poll after the window can open ~%s (measured latency %s) exceeds its maxGap %s", + ruleLabel(jobs[j].title, jobs[j].uid), gap.Round(time.Millisecond), jobs[j].latency.Round(time.Millisecond), jobs[j].maxGap)) + } + free.push(finish) + if finish.After(batchEnd) { + batchEnd = finish + } + } + now = batchEnd + i = j + } + return problems, nil +} + +// minHandoffConcurrency is the smallest concurrency in from..maxConcurrency +// whose simulated handoff fits, or 0 when even one worker per rule does not. +func minHandoffConcurrency(t map[string]RuleTimings, measured map[string]time.Duration, first []Poll, readyAt, windowOpen time.Time, from, maxConcurrency int) int { + if from < 1 { + from = 1 + } + if maxConcurrency < from { + return 0 + } + if problems, err := handoffProblems(t, measured, first, readyAt, windowOpen, maxConcurrency); err != nil || len(problems) > 0 { + return 0 + } + lo, hi := from, maxConcurrency // lo fails (the caller just checked), hi passes + for lo+1 < hi { + mid := lo + (hi-lo)/2 + problems, err := handoffProblems(t, measured, first, readyAt, windowOpen, mid) + if err == nil && len(problems) == 0 { + hi = mid + } else { + lo = mid + } + } + return hi +} + +// timeHeap is the min-heap of C worker free times within one handoff batch. +type timeHeap []time.Time + +func newTimeHeap(n int, at time.Time) *timeHeap { + h := make(timeHeap, n) + for i := range h { + h[i] = at + } + heap.Init(&h) + return &h +} + +func (h *timeHeap) pop() time.Time { + return heap.Pop(h).(time.Time) +} + +func (h *timeHeap) push(t time.Time) { + heap.Push(h, t) +} + +func (h timeHeap) Len() int { return len(h) } +func (h timeHeap) Less(i, j int) bool { return h[i].Before(h[j]) } +func (h timeHeap) Swap(i, j int) { h[i], h[j] = h[j], h[i] } +func (h *timeHeap) Push(x any) { *h = append(*h, x.(time.Time)) } +func (h *timeHeap) Pop() any { old := *h; n := len(old); x := old[n-1]; *h = old[:n-1]; return x } diff --git a/grafana-alertcheck/internal/gate/handoff_test.go b/grafana-alertcheck/internal/gate/handoff_test.go new file mode 100644 index 000000000..bdcf45f06 --- /dev/null +++ b/grafana-alertcheck/internal/gate/handoff_test.go @@ -0,0 +1,143 @@ +package gate + +import ( + "fmt" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +// One tight rule beside twenty slack ones stays safe even though the pass +// (37.8s) dwarfs the tight rule's 10s maxGap: the slack rules are not due yet. +func TestCheckStartupHandoff_MixedIntervalFleetFits(t *testing.T) { + base := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + const latency = 1800 * time.Millisecond + timings := map[string]RuleTimings{"tight": {pollEvery: 5 * time.Second, maxGap: 10 * time.Second}} + measured := map[string]time.Duration{"tight": latency} + first := []Poll{{RuleUID: "tight", GrafanaNow: base, Found: true}} + for i := range 20 { + uid := uidN(i) + timings[uid] = RuleTimings{pollEvery: 150 * time.Second, maxGap: 300 * time.Second} + measured[uid] = latency + first = append(first, Poll{RuleUID: uid, GrafanaNow: base.Add(time.Duration(i+1) * latency), Found: true}) + } + readyAt := base.Add(21 * latency) + + require.NoError(t, CheckStartupHandoff(timings, measured, first, readyAt, readyAt, 1)) +} + +// A tight rule observed late queues behind the rules due before it: 50 rules at +// 200ms make a 10s pass, so the last one's first poll is ~10s out against 8s. +func TestCheckStartupHandoff_RefusesATightRuleBehindALongBacklog(t *testing.T) { + base := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + const ( + n = 50 + latency = 200 * time.Millisecond + ) + timings := make(map[string]RuleTimings, n) + measured := make(map[string]time.Duration, n) + first := make([]Poll, 0, n) + for i := range n { + uid := fmt.Sprintf("r%03d", i) + timings[uid] = RuleTimings{title: fmt.Sprintf("Rule %03d", i), pollEvery: 4 * time.Second, maxGap: 8 * time.Second} + measured[uid] = latency + first = append(first, Poll{RuleUID: uid, GrafanaNow: base.Add(time.Duration(i) * latency), Found: true}) + } + readyAt := base.Add(n * latency) + + err := CheckStartupHandoff(timings, measured, first, readyAt, readyAt, 1) + require.Error(t, err, "a 10s backlog cannot fit an 8s maxGap") + assertBudgetMessage(t, err.Error()) + require.Contains(t, err.Error(), "raising --concurrency to at least 2", + "the error must name the concurrency that would fit, not just the lever") + require.Regexp(t, `rule "Rule \d+" \(r\d+\)`, err.Error(), + "the offending rules must be named by title, not only by UID") + + require.NoError(t, CheckStartupHandoff(timings, measured, first, readyAt, readyAt, 2), + "doubling concurrency halves the backlog drain") +} + +func TestCheckStartupHandoff_MissingInputsFailClosed(t *testing.T) { + timings := map[string]RuleTimings{"r1": {pollEvery: 30 * time.Second, maxGap: time.Minute}} + measured := map[string]time.Duration{"r1": time.Second} + + t.Run("no first observation", func(t *testing.T) { + err := CheckStartupHandoff(timings, measured, nil, testNow, testNow, 1) + require.Error(t, err, "a rule never observed cannot be proved") + require.Contains(t, err.Error(), "first observation") + }) + + t.Run("no measurement", func(t *testing.T) { + first := []Poll{{RuleUID: "r1", GrafanaNow: testNow, Found: true}} + err := CheckStartupHandoff(timings, nil, first, testNow, testNow, 1) + require.Error(t, err, "a rule never measured cannot have its backlog bounded") + require.Contains(t, err.Error(), "never measured") + }) + + t.Run("empty schedule", func(t *testing.T) { + require.NoError(t, CheckStartupHandoff(nil, nil, nil, testNow, testNow, 1)) + }) +} + +// Release delay and queueing ADD, they do not `max`: a rule due at +5s behind a +// batch released at +4.9s finishes at +9.9s, not 5.5s. +func TestCheckStartupHandoff_ReleaseDelayAndQueueAdd(t *testing.T) { + base := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + timings := make(map[string]RuleTimings, 10) + measured := make(map[string]time.Duration, 10) + first := make([]Poll, 0, 10) + + for i := range 9 { + uid := fmt.Sprintf("backlog%d", i) + timings[uid] = RuleTimings{pollEvery: 4900 * time.Millisecond, maxGap: 9800 * time.Millisecond} + measured[uid] = 500 * time.Millisecond + first = append(first, Poll{RuleUID: uid, GrafanaNow: base, Found: true}) // due +4.9s + } + timings["tight"] = RuleTimings{pollEvery: 2750 * time.Millisecond, maxGap: 5500 * time.Millisecond} + measured["tight"] = 500 * time.Millisecond + first = append(first, Poll{RuleUID: "tight", GrafanaNow: base.Add(2250 * time.Millisecond), Found: true}) // due +5s + + err := CheckStartupHandoff(timings, measured, first, base, base, 1) + require.Error(t, err, "the tight rule is polled after the 4.5s backlog it is queued behind") + require.Contains(t, err.Error(), "tight") +} + +// The recorder's whole-second `from` tolerance can open the window 999ms early, +// so the gap must be budgeted from that earlier instant. +func TestCheckStartupHandoff_BudgetsTheWholeSecondFromTolerance(t *testing.T) { + base := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + const latency = 1200 * time.Millisecond + timings := map[string]RuleTimings{ + "a": {pollEvery: 2 * time.Second, maxGap: 4 * time.Second}, + "b": {pollEvery: 2 * time.Second, maxGap: 4 * time.Second}, + "tight": {pollEvery: 2 * time.Second, maxGap: 4 * time.Second}, + } + measured := map[string]time.Duration{"a": latency, "b": latency, "tight": latency} + obs := base.Add(-1500 * time.Millisecond) // due base+0.5s, inside the first batch + first := []Poll{ + {RuleUID: "a", GrafanaNow: obs, Found: true}, + {RuleUID: "b", GrafanaNow: obs, Found: true}, + {RuleUID: "tight", GrafanaNow: obs, Found: true}, + } + readyAt := base.Add(900 * time.Millisecond) // truncates to base + + // Single-step: the clamp is exact, and the 3.6s gap fits the 4s maxGap. + require.NoError(t, CheckStartupHandoff(timings, measured, first, readyAt, readyAt, 1)) + // Recorder mode: the same run can open at base, making the gap 4.5s. + require.Error(t, CheckStartupHandoff(timings, measured, first, readyAt, readyAt.Truncate(time.Second), 1)) +} + +// A handoff that fails even at one worker per rule: no concurrency can fix it, +// so the message must not suggest raising it. +func TestCheckStartupHandoff_NoConcurrencyCanFixIt(t *testing.T) { + base := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + timings := map[string]RuleTimings{"r": {pollEvery: time.Second, maxGap: 2 * time.Second}} + measured := map[string]time.Duration{"r": 100 * time.Millisecond} + first := []Poll{{RuleUID: "r", GrafanaNow: base, Found: true}} + + err := CheckStartupHandoff(timings, measured, first, base, base.Add(-time.Second), 1) + require.Error(t, err) + require.Contains(t, err.Error(), "fix by: raising poll-interval") + require.NotContains(t, err.Error(), "raising concurrency") +} diff --git a/grafana-alertcheck/internal/gate/log.go b/grafana-alertcheck/internal/gate/log.go index f8f52d01f..68854e359 100644 --- a/grafana-alertcheck/internal/gate/log.go +++ b/grafana-alertcheck/internal/gate/log.go @@ -64,11 +64,25 @@ type LoggedRule struct { // unfiltered, so the same log can be re-classified under different --states // without re-recording. type Header struct { - SchemaVersion int `json:"schema_version"` - URL string `json:"url"` // the log's identity - GrafanaVersion string `json:"grafana_version"` - StartedAt time.Time `json:"started_at"` // the record start - Rules []LoggedRule `json:"rules"` // THE alert set + SchemaVersion int `json:"schema_version"` + URL string `json:"url"` // the log's identity + GrafanaVersion string `json:"grafana_version"` + StartedAt time.Time `json:"started_at"` // the record start + // ReadyAt is when the first-observation pass completed — the earliest + // instant a `from` can honestly name, since before it some rules were + // never observed. Zero on older logs and single-step synthesis; readyAt() + // then falls back to StartedAt. + ReadyAt time.Time `json:"ready_at,omitzero"` + Rules []LoggedRule `json:"rules"` // THE alert set +} + +// readyAt is ReadyAt when the log records it, StartedAt otherwise. The one +// place the two are collapsed, so check and proveCoverage cannot disagree. +func (h Header) readyAt() time.Time { + if h.ReadyAt.IsZero() { + return h.StartedAt + } + return h.ReadyAt } // pausedAtStart reports, per rule UID, whether the rule was paused when the diff --git a/grafana-alertcheck/internal/gate/schedule.go b/grafana-alertcheck/internal/gate/schedule.go index badd7511c..07e3f4572 100644 --- a/grafana-alertcheck/internal/gate/schedule.go +++ b/grafana-alertcheck/internal/gate/schedule.go @@ -2,6 +2,7 @@ package gate import ( "fmt" + "math" "math/rand/v2" "sort" "strings" @@ -27,8 +28,10 @@ const minDrainTimeout = 2 * time.Minute const graceWarnFraction = 0.25 // RuleTimings groups the per-rule thresholds derived from a rule's poll -// cadence and its own evaluation interval. +// cadence and its own evaluation interval. title is carried for operator-facing +// messages only — it is never compared or applied. type RuleTimings struct { + title string pollEvery time.Duration maxGap time.Duration healthGrace time.Duration @@ -86,7 +89,9 @@ func DeriveTimings(defs []Definition, override time.Duration) (rules map[string] d.Title, override, d.IntervalSeconds, def)) } } - rules[d.UID] = newRuleTimings(pollEvery, d.IntervalSeconds) + rt := newRuleTimings(pollEvery, d.IntervalSeconds) + rt.title = d.Title + rules[d.UID] = rt } // In this mode defs ARE the start-of-step snapshot, so they answer what was // paused at the window open; only the log-mode counterpart uses the header. @@ -140,7 +145,9 @@ func DeriveTimingsFromLog(h Header, defs []Definition) (rules map[string]RuleTim lr.PollEverySeconds, lr.UID, lr.Title) } pollEvery := time.Duration(lr.PollEverySeconds * float64(time.Second)) - rules[lr.UID] = newRuleTimings(pollEvery, def.IntervalSeconds) + rt := newRuleTimings(pollEvery, def.IntervalSeconds) + rt.title = def.Title // the current title: the header's may predate a rename + rules[lr.UID] = rt } // The header, not defs, decides which rules are excluded from the grace: // defs were resolved after the window closed. See deriveGlobalTimings. @@ -176,6 +183,15 @@ func deriveGlobalTimings(defs []Definition, pausedAtStart map[string]bool) Globa return g } +// ruleLabel names a rule for a human, keeping the UID for correlation: +// `"Title" (uid)`, or the bare UID when there is no title. +func ruleLabel(title, uid string) string { + if title == "" { + return uid + } + return fmt.Sprintf("%q (%s)", title, uid) +} + // Scheduler drives one per-rule schedule, never a global cycle: a rule at // intervalSeconds=10 alongside twenty at 300 keeps its own 5s cadence without // forcing the same cadence onto the other twenty. @@ -205,6 +221,42 @@ func NewScheduler(every map[string]time.Duration, now time.Time) *Scheduler { return s } +// NewSchedulerFromPolls continues an existing recording instead of starting a +// fresh phase: each rule is due one cadence after its last recorded observation, +// so the parent/child handoff keeps the spread the first-observation pass +// created and adds no stagger. An overdue rule keeps its recorded due time and +// is due immediately. Polls outside every are ignored; a rule with no recorded +// observation falls back to the fresh stagger. +func NewSchedulerFromPolls(every map[string]time.Duration, polls []Poll, now time.Time) *Scheduler { + s := &Scheduler{ + next: make(map[string]time.Time, len(every)), + every: make(map[string]time.Duration, len(every)), + } + last := make(map[string]time.Time, len(every)) + for _, p := range polls { + if _, owned := every[p.RuleUID]; !owned || p.GrafanaNow.IsZero() { + continue + } + at := runnerTime(p, p.GrafanaNow) + if cur, ok := last[p.RuleUID]; !ok || at.After(cur) { + last[p.RuleUID] = at + } + } + for uid, pollEvery := range every { + s.every[uid] = pollEvery + if at, ok := last[uid]; ok { + s.next[uid] = at.Add(pollEvery) + continue + } + var offset time.Duration + if pollEvery > 0 { + offset = rand.N(pollEvery) // nolint:gosec // spread only, same as NewScheduler + } + s.next[uid] = now.Add(offset) + } + return s +} + // Due returns the due UIDs, earliest-due-first. Ties break by tightest cadence // first: the burst bound assumes a newly-due tight rule waits at most one // in-flight request, which only holds if a simultaneous batch serves the @@ -283,10 +335,10 @@ func CheckBudget(t map[string]RuleTimings, measured map[string]time.Duration, co for _, uid := range uids { if _, ok := measured[uid]; !ok { - return fmt.Errorf("schedule budget: rule %s was never measured", uid) + return fmt.Errorf("schedule budget: rule %s was never measured", ruleLabel(t[uid].title, uid)) } if t[uid].pollEvery <= 0 { - return fmt.Errorf("schedule budget: rule %s has a non-positive poll-interval %s", uid, t[uid].pollEvery) + return fmt.Errorf("schedule budget: rule %s has a non-positive poll-interval %s", ruleLabel(t[uid].title, uid), t[uid].pollEvery) } } @@ -315,12 +367,14 @@ func CheckBudget(t map[string]RuleTimings, measured map[string]time.Duration, co } for _, uid := range overCadence { problems = append(problems, fmt.Sprintf( - "rule %s: measured %s exceeds its own poll-interval %s", uid, measured[uid], t[uid].pollEvery)) + "rule %s: measured %s exceeds its own poll-interval %s", + ruleLabel(t[uid].title, uid), measured[uid], t[uid].pollEvery)) } if maxMeasured > t[tightestUID].pollEvery { problems = append(problems, fmt.Sprintf( - "burst bound: rule %s's measured %s exceeds the fleet's tightest poll-interval %s (rule %s)", - maxMeasuredUID, maxMeasured, t[tightestUID].pollEvery, tightestUID)) + "burst bound: the slowest request is rule %s at %s, longer than the fleet's tightest poll-interval %s (rule %s)", + ruleLabel(t[maxMeasuredUID].title, maxMeasuredUID), maxMeasured, + t[tightestUID].pollEvery, ruleLabel(t[tightestUID].title, tightestUID))) } if len(problems) == 0 { @@ -330,12 +384,20 @@ func CheckBudget(t map[string]RuleTimings, measured map[string]time.Duration, co var b strings.Builder fmt.Fprintf(&b, "schedule does not fit at concurrency %d:\n", concurrency) for _, uid := range uids { - fmt.Fprintf(&b, " rule %s: measured %s, poll-interval %s\n", uid, measured[uid], t[uid].pollEvery) + fmt.Fprintf(&b, " rule %s: measured %s, poll-interval %s\n", + ruleLabel(t[uid].title, uid), measured[uid], t[uid].pollEvery) } for _, p := range problems { fmt.Fprintf(&b, " - %s\n", p) } - b.WriteString("fix by: raising concurrency, raising poll-interval, or watching fewer alerts") + // Utilization is the one condition concurrency fixes, so name the exact + // value; the other two are single-request shapes no concurrency shortens. + if utilization > float64(concurrency) { + fmt.Fprintf(&b, "fix by: raising --concurrency to at least %d (currently %d), raising poll-interval, or watching fewer alerts", + int(math.Ceil(utilization)), concurrency) + } else { + b.WriteString("fix by: raising poll-interval or watching fewer alerts") + } return fmt.Errorf("%s", b.String()) } diff --git a/grafana-alertcheck/internal/gate/schedule_test.go b/grafana-alertcheck/internal/gate/schedule_test.go index f71fbbfc2..e46fc33b5 100644 --- a/grafana-alertcheck/internal/gate/schedule_test.go +++ b/grafana-alertcheck/internal/gate/schedule_test.go @@ -244,6 +244,41 @@ func TestNewScheduler_StaggersWithinPollEvery(t *testing.T) { require.Less(t, offset, 100*time.Second) } +// The handoff scheduler continues the recorded schedule — last observation plus +// cadence — so the child adds no fresh stagger; an overdue rule is due +// immediately. +func TestNewSchedulerFromPolls_ContinuesTheRecordedCadence(t *testing.T) { + now := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + polls := []Poll{ + {RuleUID: "r1", GrafanaNow: now.Add(-2 * time.Minute)}, + {RuleUID: "r1", GrafanaNow: now.Add(-90 * time.Second)}, // the latest observation wins + {RuleUID: "stranger", GrafanaNow: now}, // not in the cadence map + } + every := map[string]time.Duration{"r1": 30 * time.Second, "fresh": 10 * time.Second} + s := NewSchedulerFromPolls(every, polls, now) + + require.Equal(t, now.Add(-60*time.Second), s.next["r1"], "last observation + cadence, kept in the past") + require.Contains(t, s.Due(now), "r1", "an overdue rule must be due immediately") + + // No recorded observation: the fresh stagger applies, as it does for a + // hand-started child. + offset := s.next["fresh"].Sub(now) + require.GreaterOrEqual(t, offset, time.Duration(0)) + require.Less(t, offset, 10*time.Second) + + _, ok := s.next["stranger"] + require.False(t, ok, "a poll of a rule the scheduler does not own must not create an entry") +} + +// The seed uses the runner-domain observation time (GrafanaNow - skew), so a +// skewed poll does not shift the schedule. +func TestNewSchedulerFromPolls_TranslatesSkew(t *testing.T) { + now := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + polls := []Poll{{RuleUID: "r1", GrafanaNow: now, SkewMS: 1500}} + s := NewSchedulerFromPolls(map[string]time.Duration{"r1": time.Minute}, polls, now) + require.Equal(t, now.Add(-1500*time.Millisecond).Add(time.Minute), s.next["r1"]) +} + func TestScheduler_EarliestDueEmpty(t *testing.T) { s := &Scheduler{next: map[string]time.Time{}, every: map[string]time.Duration{}} _, ok := s.earliestDue() @@ -288,6 +323,21 @@ func TestCheckBudget_MixedIntervalRegression(t *testing.T) { require.NoError(t, CheckBudget(timings, measured, 1)) } +// The budget error is read by a human: a titled rule must be named by its +// title, with the UID kept for machine correlation. +func TestCheckBudget_NamesRulesByTitle(t *testing.T) { + timings := map[string]RuleTimings{ + "a": {title: "WorkflowLimit Exceeded", pollEvery: 10 * time.Second}, + "b": {title: "Node Down", pollEvery: 10 * time.Second}, + } + measured := map[string]time.Duration{"a": 9 * time.Second, "b": 9 * time.Second} + + err := CheckBudget(timings, measured, 1) + require.Error(t, err) + require.Contains(t, err.Error(), `rule "WorkflowLimit Exceeded" (a): measured`) + require.Contains(t, err.Error(), `rule "Node Down" (b): measured`) +} + func TestCheckBudget_UtilizationExceeded(t *testing.T) { timings := map[string]RuleTimings{ "a": {pollEvery: 10 * time.Second}, @@ -297,6 +347,8 @@ func TestCheckBudget_UtilizationExceeded(t *testing.T) { err := CheckBudget(timings, measured, 1) require.Error(t, err) assertBudgetMessage(t, err.Error()) + require.Contains(t, err.Error(), "raising --concurrency to at least 2", + "utilization 1.8 needs concurrency 2; the error must name it") } func TestCheckBudget_SingleRuleExceedsOwnCadence(t *testing.T) { @@ -305,6 +357,8 @@ func TestCheckBudget_SingleRuleExceedsOwnCadence(t *testing.T) { err := CheckBudget(timings, measured, 10) require.Error(t, err, "measured 6s exceeds its own 5s poll-interval") assertBudgetMessage(t, err.Error()) + require.NotContains(t, err.Error(), "raising concurrency", + "concurrency cannot shorten a single request") } func TestCheckBudget_BurstBoundViolation(t *testing.T) { @@ -320,6 +374,8 @@ func TestCheckBudget_BurstBoundViolation(t *testing.T) { require.Error(t, err, "slow's 3s measured exceeds tight's 2s cadence") require.Contains(t, err.Error(), "burst bound") assertBudgetMessage(t, err.Error()) + require.NotContains(t, err.Error(), "raising concurrency", + "concurrency cannot shorten a single request") } func TestCheckBudget_BurstBoundOKWhenNotExceeded(t *testing.T) { diff --git a/grafana-alertcheck/internal/gate/source_fake_test.go b/grafana-alertcheck/internal/gate/source_fake_test.go index 97de92f02..fe5e1e470 100644 --- a/grafana-alertcheck/internal/gate/source_fake_test.go +++ b/grafana-alertcheck/internal/gate/source_fake_test.go @@ -66,6 +66,15 @@ func (c *virtualClock) Now() time.Time { return c.now } +// Advance moves the clock without a wait. It exists for a test that must model +// time passing inside a non-waiting section — the measurement pass of a +// single-step check — while collectUntil below still advances through After. +func (c *virtualClock) Advance(d time.Duration) { + c.mu.Lock() + defer c.mu.Unlock() + c.now = c.now.Add(d) +} + func (c *virtualClock) After(d time.Duration) <-chan time.Time { c.mu.Lock() if d > 0 { diff --git a/grafana-alertcheck/internal/gate/watch.go b/grafana-alertcheck/internal/gate/watch.go index 4598bcad0..5161d5dee 100644 --- a/grafana-alertcheck/internal/gate/watch.go +++ b/grafana-alertcheck/internal/gate/watch.go @@ -132,8 +132,8 @@ func (cfg WatchConfig) validate() error { } // Watch is the record step's parent process, returning only once the window is -// genuinely being recorded (version gate, resolve, write header, one -// observation per rule, budget check, then detach and await the child's +// genuinely being recorded (version gate, resolve, one observation per rule, +// budget check, header with ReadyAt, then detach and await the child's // readiness). The first-observation wait is what surfaces auth, name-resolution // and parse failures before deploy.sh runs, rather than ten minutes later. func Watch(ctx context.Context, cfg WatchConfig) error { @@ -330,22 +330,22 @@ func prepareWatch(ctx context.Context, cfg WatchConfig, src Source) (*preparedWa return prep, nil } -// openRecording writes the header, takes the first observation of every rule -// the recorder will actually watch, appends those observations as the log's -// first heartbeats, and only then decides whether the schedule is feasible. +// openRecording takes the first observation of every rule the recorder will +// actually watch, checks the budget, and only then writes the header and those +// observations. The header's ReadyAt is the pass completion — the earliest +// `from` a coverage proof can honestly start at — so the header must be written +// after the pass, not before it. func openRecording(ctx context.Context, cfg WatchConfig, src Source, writer *Writer, version string, resolved []Definition, rt map[string]RuleTimings) (*preparedWatch, error) { + startedAt := cfg.Clock.Now() header := Header{ SchemaVersion: LogSchemaVersion, URL: cfg.URL, GrafanaVersion: version, - StartedAt: cfg.Clock.Now(), + StartedAt: startedAt, Rules: loggedRules(resolved, rt), } - if err := writer.WriteHeader(header); err != nil { - return nil, err - } // A rule whose definition says is_paused is skipped (never waited for or // polled); polling it would report an in-window pause (check 7) for a rule @@ -367,22 +367,53 @@ func openRecording(ctx context.Context, cfg WatchConfig, src Source, writer *Wri if err != nil { return nil, err } + + // The pass is over; the seed will start from this instant, so both budget + // checks judge the schedule the child will actually run. + readyAt := cfg.Clock.Now() + + // Budget before the header, on the latencies just measured — never on a + // fixed estimate. Only the active rules count: a skipped rule is never + // polled and consumes none of the capacity. + if err := CheckBudget(activeTimings, measured, cfg.Concurrency); err != nil { + return nil, err + } + // The from-bounds tolerance can open the window a whole second early. + if err := CheckStartupHandoff(activeTimings, measured, polls, readyAt, readyAt.Truncate(time.Second), cfg.Concurrency); err != nil { + return nil, err + } + + header.ReadyAt = readyAt + if tightest := tightestPollEvery(activeTimings); tightest > 0 { + if pass := header.ReadyAt.Sub(header.StartedAt); pass > tightest { + fmt.Fprintf(cfg.Notes, "warning: the first observation pass took %s, longer than the tightest poll-interval %s; `from` must be emitted after this command returns or the first window can open with a gap\n", + pass.Round(time.Millisecond), tightest) + } + } + if err := writer.WriteHeader(header); err != nil { + return nil, err + } for _, p := range polls { if err := writer.WritePoll(p); err != nil { return nil, err } } - // Budget last, on the latencies just measured — never on a fixed estimate. - // Only the active rules count: a skipped rule is never polled and consumes - // none of the capacity. - if err := CheckBudget(activeTimings, measured, cfg.Concurrency); err != nil { - return nil, err - } - return &preparedWatch{writer: writer, header: header, timings: rt, measured: measured}, nil } +// tightestPollEvery is the smallest cadence among the rules that will be +// polled, or zero when none will. +func tightestPollEvery(t map[string]RuleTimings) time.Duration { + var tightest time.Duration + for _, rt := range t { + if tightest == 0 || rt.pollEvery < tightest { + tightest = rt.pollEvery + } + } + return tightest +} + // loggedRules snapshots the resolved definitions into the header's rule list. // Every field but PollEverySeconds is forensic — a resolve-time snapshot that // makes an uploaded log self-describing — while PollEverySeconds is @@ -457,40 +488,49 @@ func firstObservations(ctx context.Context, src Source, active []Definition, red return polls, measured, nil } -// observeAll polls every rule in uids concurrently, bounded by concurrency, -// returning one Observation per rule that answered. Each rule is polled by -// TITLE (the ?rule_name= filter is a title filter) and selected by UID — a -// filtered response can carry several rules sharing a title. Returns the -// successes alongside the first error in UID order, so a caller can keep the -// good heartbeats. +// observeAll polls every rule in uids with at most concurrency requests in +// flight, dispatching in uids order (a worker takes the next uid as it frees) +// so the startup-handoff simulation matches. Polls by TITLE, selects by UID, +// and returns the first error in UID order alongside the successes. func observeAll(ctx context.Context, src Source, titles map[string]string, uids []string, concurrency int) (map[string]Observation, error) { if concurrency < 1 { concurrency = 1 } + if concurrency > len(uids) { + concurrency = len(uids) + } var ( mu sync.Mutex out = make(map[string]Observation, len(uids)) firstErr error firstErrUID string + next int ) - sem := make(chan struct{}, concurrency) var wg sync.WaitGroup - for _, uid := range uids { + for range concurrency { wg.Go(func() { - sem <- struct{}{} - defer func() { <-sem }() - - obs, err := src.RuleState(ctx, titles[uid]) - - mu.Lock() - defer mu.Unlock() - if err != nil { - if firstErr == nil || uid < firstErrUID { - firstErr, firstErrUID = err, uid + for { + mu.Lock() + if next == len(uids) { + mu.Unlock() + return + } + uid := uids[next] + next++ + mu.Unlock() + + obs, err := src.RuleState(ctx, titles[uid]) + + mu.Lock() + if err != nil { + if firstErr == nil || uid < firstErrUID { + firstErr, firstErrUID = err, uid + } + } else { + out[uid] = obs } - return + mu.Unlock() } - out[uid] = obs }) } wg.Wait() @@ -585,6 +625,7 @@ func RunDaemonChild(ctx context.Context, cfg DaemonChildConfig) error { Reducer: reducer, Titles: titles, Cadence: cadence, + Seed: polls, Until: cfg.Until, Concurrency: cfg.Concurrency, Clock: cfg.Clock, @@ -638,11 +679,14 @@ func childSchedule(h Header) (titles map[string]string, cadence map[string]time. // where to append it. There is no threshold in here and no policy — the child // records and classifies nothing. type watchLoopConfig struct { - Src Source - Writer *Writer - Reducer *Reducer - Titles map[string]string // uid -> title: poll by title, select by UID - Cadence map[string]time.Duration // uid -> pollEvery, as recorded in the header + Src Source + Writer *Writer + Reducer *Reducer + Titles map[string]string // uid -> title: poll by title, select by UID + Cadence map[string]time.Duration // uid -> pollEvery, as recorded in the header + // Seed is the polls already in the log when this loop starts: it continues + // their schedule instead of re-staggering. nil means a fresh schedule. + Seed []Poll Until time.Time Concurrency int Clock Clock @@ -657,6 +701,9 @@ type watchLoopConfig struct { // coverage gap to check, because it is one. func watchLoop(ctx context.Context, cfg watchLoopConfig) error { sched := NewScheduler(cfg.Cadence, cfg.Clock.Now()) + if len(cfg.Seed) > 0 { + sched = NewSchedulerFromPolls(cfg.Cadence, cfg.Seed, cfg.Clock.Now()) + } for { if ctx.Err() != nil { diff --git a/grafana-alertcheck/internal/gate/watch_daemon_test.go b/grafana-alertcheck/internal/gate/watch_daemon_test.go index 830b82bb0..04c1276e9 100644 --- a/grafana-alertcheck/internal/gate/watch_daemon_test.go +++ b/grafana-alertcheck/internal/gate/watch_daemon_test.go @@ -208,8 +208,8 @@ func waitFor(t *testing.T, what string, timeout time.Duration, cond func() bool) // It asserts the four things only a real spawn can show — the pidfile points // at a live process, that process is in its own session (setsid, not a bare // `&`), it keeps appending after Watch returned, and SIGTERM makes it finish -// the log in the stop order — and it uses a 200ms --poll-interval to do it in -// about a second, which also exercises the unclamped-override path. +// the log in the stop order — with a 2s --poll-interval, which also exercises +// the unclamped-override path. func TestWatchSpawnsADetachedRecorder(t *testing.T) { srv := grafanaTestServer(t) t.Setenv("GRAFANA_URL", srv.URL) @@ -222,7 +222,7 @@ func TestWatchSpawnsADetachedRecorder(t *testing.T) { Token: testBearerToken, Alerts: []string{"uid:" + watchActiveUID}, Out: out, - PollEvery: 200 * time.Millisecond, + PollEvery: 2 * time.Second, Concurrency: 2, Notes: ¬es, } @@ -264,7 +264,7 @@ func TestWatchSpawnsADetachedRecorder(t *testing.T) { require.Equal(t, srv.URL, header.URL) require.Equal(t, "13.1.0", header.GrafanaVersion) require.Len(t, header.Rules, 1) - require.Equal(t, float64(0.2), header.Rules[0].PollEverySeconds) + require.Equal(t, float64(2), header.Rules[0].PollEverySeconds) for i, p := range polls { require.Equalf(t, watchActiveUID, p.RuleUID, "poll %d", i) require.Truef(t, p.Found, "poll %d", i) @@ -322,7 +322,6 @@ func TestWatchFailsWhenTheChildCannotStartRecording(t *testing.T) { Token: testBearerToken, Alerts: []string{"uid:" + watchActiveUID}, Out: out, - PollEvery: 200 * time.Millisecond, Concurrency: 2, Notes: ¬es, }) diff --git a/grafana-alertcheck/internal/gate/watch_test.go b/grafana-alertcheck/internal/gate/watch_test.go index 8342b7f14..8d03ef302 100644 --- a/grafana-alertcheck/internal/gate/watch_test.go +++ b/grafana-alertcheck/internal/gate/watch_test.go @@ -136,6 +136,56 @@ func TestWatchLoopPollsEachRuleAtItsOwnCadence(t *testing.T) { require.LessOrEqual(t, got, 3) } +// A seeded, already-overdue rule is polled at the loop's first instant, with no +// fresh stagger added on top of the parent's pass. +func TestWatchLoopContinuesTheSeededSchedule(t *testing.T) { + path := filepath.Join(t.TempDir(), "log.jsonl") + clock := newVirtualClock(testNow) + w := newLoopWriter(t, path, clock) + + src := newLoopSource(func(title string, _ int) (Observation, error) { + now := clock.Now() + return observation(now, testStateRule("r1", title, time.Minute, now)), nil + }) + + require.NoError(t, watchLoop(context.Background(), watchLoopConfig{ + Src: src, + Writer: w, + Reducer: NewReducer(), + Titles: map[string]string{"r1": "Example"}, + Cadence: map[string]time.Duration{"r1": 30 * time.Second}, + Seed: []Poll{{RuleUID: "r1", GrafanaNow: testNow.Add(-90 * time.Second), Found: true}}, + Until: testNow.Add(time.Minute), + Concurrency: 1, + Clock: clock, + })) + + _, polls, _, err := ReadLog(path) + require.NoError(t, err) + require.NotEmpty(t, polls) + require.True(t, polls[0].GrafanaNow.Equal(testNow), + "the first poll must be the seeded due time (now), not a fresh stagger") +} + +// observeAll dispatches in uids order, which the handoff proof assumes. +func TestObserveAllDispatchesInOrder(t *testing.T) { + var mu sync.Mutex + var order []string + src := newLoopSource(func(title string, _ int) (Observation, error) { + mu.Lock() + order = append(order, title) + mu.Unlock() + return observation(testNow, testStateRule(title, title, time.Minute, testNow)), nil + }) + uids := []string{"r1", "r2", "r3", "r4"} + titles := map[string]string{"r1": "One", "r2": "Two", "r3": "Three", "r4": "Four"} + + out, err := observeAll(context.Background(), src, titles, uids, 1) + require.NoError(t, err) + require.Len(t, out, 4) + require.Equal(t, []string{"One", "Two", "Three", "Four"}, order) +} + // Fail-closed from the recorder's side: a recorder that dies must look exactly // like a coverage gap, so it must not sign off the log on its way out. func TestWatchLoopHardErrorLeavesNoSentinel(t *testing.T) { @@ -395,6 +445,62 @@ func TestPrepareWatchHeaderRecordsTheOverriddenCadence(t *testing.T) { require.Contains(t, notes.String(), "--poll-interval") } +// ReadyAt must be stamped after the first-observation pass, never before it: +// that is what lets check refuse a `from` inside the pass. StartedAt stays the +// record start, captured before the pass. +func TestOpenRecordingStampsReadyAtAfterTheFirstObservationPass(t *testing.T) { + var notes strings.Builder + clock := newFakeClock(testNow) + cfg := watchTestConfig(t, ¬es, "uid:"+watchActiveUID) + cfg.Clock = clock + + src := newCheckSource(func(title string, _ int) (Observation, error) { + clock.Advance(5 * time.Second) + now := clock.Now() + return observation(now, testStateRule(watchActiveUID, watchActiveTitle, time.Minute, now, + testInstance(StateNormal, "", "a"))), nil + }) + src.version = "13.1.0" + src.defs = rulerDefs(t) + + prep, err := prepareWatch(context.Background(), cfg, src) + require.NoError(t, err) + require.NoError(t, prep.writer.Close()) + + require.Equal(t, testNow, prep.header.StartedAt, "StartedAt is the record start, captured before the pass") + require.Equal(t, testNow.Add(5*time.Second), prep.header.ReadyAt, "ReadyAt must be stamped after the pass completes") + + header, polls, _, err := ReadLog(cfg.Out) + require.NoError(t, err) + require.Equal(t, prep.header.ReadyAt, header.ReadyAt, "ReadyAt must round-trip through the log") + require.Len(t, polls, 1) + require.False(t, polls[0].GrafanaNow.After(header.ReadyAt), + "the first observation cannot postdate the readiness it proves") +} + +// A pass longer than the tightest poll-interval is the startup shape that opens +// a gap; warn at the source. +func TestOpenRecordingWarnsWhenTheStartupPassExceedsTheTightestCadence(t *testing.T) { + var notes strings.Builder + clock := newFakeClock(testNow) + cfg := watchTestConfig(t, ¬es, "uid:"+watchActiveUID) + cfg.Clock = clock + + src := newCheckSource(func(title string, _ int) (Observation, error) { + clock.Advance(31 * time.Second) // longer than the rule's 30s poll-interval + now := clock.Now() + return observation(now, testStateRule(watchActiveUID, watchActiveTitle, time.Minute, now, + testInstance(StateNormal, "", "a"))), nil + }) + src.version = "13.1.0" + src.defs = rulerDefs(t) + + prep, err := prepareWatch(context.Background(), cfg, src) + require.NoError(t, err) + require.NoError(t, prep.writer.Close()) + require.Contains(t, notes.String(), "first observation pass took") +} + // The budget check runs on the latencies the parent just measured, before the // deploy runs. func TestPrepareWatchFailsWhenTheScheduleDoesNotFit(t *testing.T) { @@ -425,11 +531,12 @@ func TestPrepareWatchVerifiesNormalInstancesAreVisible(t *testing.T) { require.Error(t, err, "totals claim normal instances the response omitted") require.Contains(t, err.Error(), "no longer returns normal instances") - // The failure happens before any poll is appended, so the log holds a - // header and nothing else. - _, polls, _, readErr := ReadLog(cfg.Out) - require.NoError(t, readErr) - require.Empty(t, polls) + // The failure happens during the pass, before the header is written, so the + // log holds neither a header nor a poll — still unreadable, still fail + // closed. + info, statErr := os.Stat(cfg.Out) + require.NoError(t, statErr) + require.Zero(t, info.Size(), "a failed first-observation pass left bytes in the log") } func TestPrepareWatchRejectsAnUnsupportedGrafana(t *testing.T) {