Skip to main content

· Forensic case study

The 2-minute recording lag that cost a payments burn 130 seconds

A three-level recording cascade evaluates behind the alert reading it — the classifier attributes a 130-second page delay to the 2-minute lag, and prescribes shortening the recording group instead of the alert.

The rule

PaymentsLatencySLOBurn sits at the top of a three-level recording cascade, split across two groups with two different evaluation intervals:

Terminal
groups:
  - name: payments-latency-slis
    interval: 2m
    rules:
      - record: job:api_latency:good_rate5m
        expr: rate(api_request_duration_seconds_count{job="payments",le="0.3"}[5m])
        labels:
          job: payments
      - record: job:api_latency:total_rate5m
        expr: rate(api_request_duration_seconds_count{job="payments",le="+Inf"}[5m])
        labels:
          job: payments
  - name: payments-latency-slo
    interval: 1m
    rules:
      - record: job:api_latency:good_ratio5m
        expr: job:api_latency:good_rate5m / job:api_latency:total_rate5m
        labels:
          job: payments
      - alert: PaymentsLatencySLOBurn
        expr: (1 - job:api_latency:good_ratio5m{job="payments"}) > 0.02
        for: 2m
        labels:
          severity: critical
          slo: payments-latency
        annotations:
          summary: Payments latency SLO burning error budget

The leaf group — the two rate5m recording rules the ratio is built from — evaluates every 2 minutes. The group holding the ratio and the alert evaluates every 1 minute. Every time PaymentsLatencySLOBurn runs, there is up to a 2-minute-old pair of rate5m values sitting under it, because the group that produces them has not necessarily run again since.

What the lag costs

BurnRateSurgeon's classifier does not need the raw time series to name this failure — it reasons over the structural evidence a cascade like this one produces, the same evidence packages/cli/src/replay/precision.test.ts pins as the scenario's ground truth:

Terminal
neutralInput('PaymentsLatencySLOBurn', {
  recordingLag: {
    alertDependsOnRecordingRule: true,
    recordingRuleEvalLagSeconds: 120,
    evaluationIntervalSeconds: 60,
    pageDelaySeconds: 130,
  },
});

Fed that evidence, classify() names the class, attaches a fix, and reports its own confidence — 0.7 plus a quarter of how much of the 130-second delay the 120-second lag explains (here, all but ten seconds of it):

Terminal
rootCause:  recording_rule_eval_lag
confidence: 0.93
explanation: PaymentsLatencySLOBurn paged 130s late because it reads a recorded metric
             whose evaluation lag is 2m. Shorten the recording group's interval (or alert
             on the raw series) so the derived value is fresh when the rule evaluates
             (recording_rule_eval_lag).

packages/classifier/src/classify.test.ts and the precision suite both hold this exact scenario to that exact root cause — one of the six canonical classes, at 100% precision across the synthetic set, as packages/cli/src/replay/precision.test.ts requires.

Replaying it

The fixture is fixtures/scenarios/recording_rule_eval_lag/ — the same trio (snapshot, rules, Alertmanager config) brs replay consumes for any target:

Terminal
git clone https://github.com/BurnRateSurgeon/burnratesurgeon
cd burnratesurgeon
pnpm install
pnpm --filter @burnratesurgeon/cli build
node packages/cli/dist/index.js replay \
  --tsdb fixtures/scenarios/recording_rule_eval_lag \
  --rules fixtures/scenarios/recording_rule_eval_lag/rules.yml \
  --alertmanager fixtures/scenarios/recording_rule_eval_lag/alertmanager.yml
Terminal
# brs replay report

- Engine: 1.0.0
- Window: 1970-01-01T00:00:00.000Z → 1970-01-02T00:00:00.000Z
- Alerts simulated: 0
- Root-cause findings: 0
- Critical findings: 0

The report is empty for the same reason the window_boundary_miss fixture's report was: the per-class evidence extractor that lets brs replay pull a finding like the one above straight out of a raw snapshot has not landed yet (fixtures/scenarios/README.md tracks this as the additive follow-up to the classification-accuracy work). What is real today is the classification: the ground-truth evidence this fixture encodes, run through the same classify() the CLI calls, names recording_rule_eval_lag correctly, every time packages/cli/src/replay/precision.test.ts runs in CI.

Why the cascade lags

A recording rule is not a live view of its input — it is a value computed the last time its group evaluated, held until the next one. Stack two groups with different intervals and the faster one is, at any given instant, reading a value that is on average half its own interval old and, at worst, almost the slower group's entire interval old. Here that worst case is 2 minutes: long enough that a for: 2m alert built on top of it can clear its own condition and still not page until the stale ratio catches up. The rule's for: clause was sized against the incident, not against the staleness of what it reads.

The fix

Nothing about the alert's math is wrong — the ratio, the 2% threshold, the for: 2m, are all correct. The fix is upstream, in how fresh the recording cascade is allowed to be relative to the group reading it:

Terminal
   - name: payments-latency-slis
-    interval: 2m
+    interval: 1m
     rules:
       - record: job:api_latency:good_rate5m
         expr: rate(api_request_duration_seconds_count{job="payments",le="0.3"}[5m])

Matching the leaf group's interval to the alert group's halves the worst-case staleness from 2 minutes to 1, which is the general shape of the fix the classifier prescribes for this class: shorten the recording group's interval, or skip the recording rule entirely and let the alert read the raw series where the extra query cost is affordable. Either way, the check before merging the change is the same one this repository runs on every commit: replay it against history and confirm the delay the cascade adds is now smaller than the for: clause sitting on top of it.