Skip to content

Say what secondary_lag_seconds actually measures (#991) - #1703

Merged
erikdarlingdata merged 5 commits into
devfrom
feature/991-ag-lag-semantics
Jul 26, 2026
Merged

Say what secondary_lag_seconds actually measures (#991)#1703
erikdarlingdata merged 5 commits into
devfrom
feature/991-ag-lag-semantics

Conversation

@erikdarlingdata

Copy link
Copy Markdown
Owner

Follow-up to #1700. That PR got the rule right but the mechanism wrong, and the mechanism is what an operator needs in order to tune a threshold. Documentation and alert text only -- no logic change.

Reconciling two measurements

ag-fixture-builder worked out why their samples started near 0 and mine started near 3993: theirs was under write load, mine was idle. While suspended the column reports the staleness of the last hardened log (roughly now - last_hardened_time), which then grows at wall-clock rate. It is not time since suspension. Under load the last hardening is near-now, so it starts around 0 and climbs; on an idle group it starts at however long since the last write, so it can jump straight to a large number. Same behavior, different starting points -- neither measurement was wrong.

The sharper finding

Chasing that turned up something more important, which I measured myself on the idle fixture rather than taking second-hand. Sampled every 15 seconds across a 60-second suspend with no write load:

elapsed  susp  lag  redo  send  state              secs_since_hardened
0        1     0    0     NULL  NOT SYNCHRONIZING  262
15       1     0    0     NULL  NOT SYNCHRONIZING  277
30       1     0    0     NULL  NOT SYNCHRONIZING  292
45       1     0    0     NULL  NOT SYNCHRONIZING  307
60       1     0    0     NULL  NOT SYNCHRONIZING  322

Lag read 0 at every sample while the replica was already NOT SYNCHRONIZING and its last hardened log aged past five minutes. It did not latch late -- it never latched. (ag-fixture-builder saw it latch at +30s on their idle run, so the timing varies; the operational fact does not.)

Two consequences

1. A suspended replica can report zero lag for an entire outage. #1700's rule -- a sub-threshold reading on a suspended row yields NotMeasurable, never CaughtUp -- is what stops that zero from clearing a standing alarm on a replica that is receiving nothing. The rule was built for the inverted-docs case and turns out to be load-bearing for a completely different and more common one.

2. The lag trigger alone cannot detect suspended data movement on a quiet group. AG Database Suspended is the alert that owns that case. Worth stating plainly in the code, because the obvious assumption is that a lag threshold covers it.

Operator-facing change

The alert detail text now says what the number is: staleness of the last hardened log, not volume of queued data. On a quiet group a large lag can simply mean nothing has been written recently. The volume measure would be log_send_queue_size -- and that reads NULL while suspended, so there is no queued-bytes figure available for a suspended replica at all.

Testing

Darling suite green: 3252 passed, 0 failed. The existing "suspended row under threshold yields NotMeasurable" assertion is unchanged in behavior but its comment now cites the measured never-latches case rather than describing it as a hypothetical.

The fixture was left SYNCHRONIZED and healthy.

🤖 Generated with Claude Code

erikdarlingdata and others added 2 commits July 26, 2026 15:17
Follow-up to #1700. That PR got the RULE right but the MECHANISM wrong, and the
mechanism is what an operator needs to tune a threshold.

ag-fixture-builder reconciled why their measurement started near 0 and mine
started near 3993: theirs was under write load, mine was idle. While suspended
the column reports the staleness of the last hardened log (roughly
now - last_hardened_time), which then grows at wall-clock rate. It is NOT time
since suspension. Under load the last hardening is near-now so it starts around
0 and climbs; on an idle group it starts at however long since the last write,
so it can jump straight to a large number. Same behavior, different starting
points - neither measurement was wrong.

Chasing that turned up something sharper, which I measured myself on the idle
fixture rather than taking second-hand. Sampled every 15 seconds across a
60-second suspend with no write load:

  elapsed  susp  lag  redo  send  state              secs_since_hardened
  0        1     0    0     NULL  NOT SYNCHRONIZING  262
  15       1     0    0     NULL  NOT SYNCHRONIZING  277
  30       1     0    0     NULL  NOT SYNCHRONIZING  292
  45       1     0    0     NULL  NOT SYNCHRONIZING  307
  60       1     0    0     NULL  NOT SYNCHRONIZING  322

Lag read 0 at EVERY sample while the replica was already NOT SYNCHRONIZING and
its last hardened log aged past five minutes. It did not latch late, it never
latched. (ag-fixture-builder saw it latch at +30s on their idle run, so the
timing varies; the operational fact does not.)

Two things follow, and #1700's asymmetry already survives both - this commit is
documentation and alert text, no logic change:

1. A suspended replica can report zero lag for an entire outage. "A sub-threshold
   reading on a suspended row yields NotMeasurable, never CaughtUp" is what stops
   that zero from clearing a standing alarm on a replica receiving nothing. The
   rule was built for the inverted-docs case and turns out to be load-bearing for
   a completely different and more common one.

2. THE LAG TRIGGER ALONE CANNOT DETECT SUSPENDED DATA MOVEMENT on a quiet group.
   "AG Database Suspended" is the alert that owns that case. Worth stating
   plainly, because the obvious assumption is that a lag threshold covers it.

The alert detail text now also says what the number is: staleness of the last
hardened log, not volume of queued data. On a quiet group a large lag can simply
mean nothing has been written recently. The volume measure would be
log_send_queue_size, and that reads NULL while suspended - so there is no
queued-bytes figure available for a suspended replica at all.

Darling suite green: 3252 passed. Fixture left SYNCHRONIZED.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
erikdarlingdata and others added 3 commits July 26, 2026 15:22
#991)

ag-collector-builder measured the four new *_time columns under suspension
(#1702) and the result generalizes the rule rather than adding a footnote to it.

All four freeze at their last pre-suspension instant. So a cross-replica
commit-time delta STOPS GROWING exactly when replication stops - it reads as
though the secondary is catching up at the moment it has stopped receiving
anything. The sharpest case is any drain-time measure: queue divided by rate
with both frozen holds a small, static, healthy-looking number (measured at a
flat 0.0144 minutes across an entire suspension) when the true answer is "never,
movement is stopped".

That is the same failure as the lag zero and the frozen redo queue, but arrived
at three different ways, and every one of them errs in the REASSURING direction.
A drain-time or commit-delta trigger wired in here would fail SILENT rather than
loud, which is the worse half.

So the doc block now states the invariant as a property of suspended ROWS -
anything new that judges one must route through the same may-fire-never-clear
gate - instead of reading as two column-specific carve-outs that a future
trigger would not obviously be covered by. No logic change: the gate already
sits at the single exit point, so a new trigger inherits it by construction as
long as nobody adds an early return above it.

Also on record from that run, neither affecting this evaluator: last_commit_time
is not a heartbeat (it sits still on an idle database, and 7 minutes of apparent
"lag" was measured on a caught-up secondary reporting secondary_lag_seconds = 0),
so now - last_commit_time is not a lag measure and would page on quiet
databases; and last_received_time read NULL in every sample, healthy or
suspended.

Their run is also an independent third confirmation of the lag behavior
(30/45/60/75 under load on a separate run).

Darling suite green: 3252 passed.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
References #1702 without a link-ref on purpose - that PR will add its own,
and two branches adding the same link-ref is a guaranteed CHANGELOG conflict.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@erikdarlingdata
erikdarlingdata merged commit 6d6a157 into dev Jul 26, 2026
4 checks passed
@erikdarlingdata
erikdarlingdata deleted the feature/991-ag-lag-semantics branch July 26, 2026 20:02
pull Bot pushed a commit to ehtick/PerformanceMonitor that referenced this pull request Jul 29, 2026
…ag claim

erikdarlingdata#1702 and erikdarlingdata#1703 both cite tools/ag-fixture/VALIDATION.md for how a suspended
row behaves, and the file did not contain the measurements behind several of
those claims. This lands them.

It also corrects something I got wrong in erikdarlingdata#1704. I wrote that
secondary_lag_seconds "only latched at the +30s sample", which implied a short
bounded window. ag-alerts-builder measured it never latching across a whole
60s suspension on a quiet group, and I reproduced that independently here: 0
at every sample through a full 60-second suspension, already NOT
SYNCHRONIZING, with the last hardened log ~29 minutes stale. One earlier idle
run latched at +30s and these did not, so the timing is not dependable in
either direction. The file now says so, and states the consequence plainly: a
lag threshold alone cannot detect suspended data movement on a quiet group.

Also added, with sample tables from a loaded run and an idle one:

- All four *_time columns freeze at their last pre-suspension instant, so a
  cross-replica commit-time delta stops growing exactly when replication
  stops - the opposite direction from secondary_lag_seconds.
- redo_queue_size freezes rather than growing.
- est_redo_completion_time_min is the sharpest edge: queue over rate with both
  frozen holds a small static reassuring number for the whole suspension
  (0.0144 min loaded, 0 idle), so a suspended replica looks healthier than a
  working one.
- last_received_time read NULL in every sample on both runs.
- last_commit_time is not a heartbeat - measured 1757 seconds behind wall
  clock on a SYNCHRONIZED, non-suspended, zero-lag replica, purely because the
  database was quiet.

Loaded-run table is ag-collector-builder's; the idle run and the never-latch
reproduction are mine. Evidence file and CHANGELOG only, no code.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
pull Bot pushed a commit to ehtick/PerformanceMonitor that referenced this pull request Jul 29, 2026
…lingdata#991)

erikdarlingdata#1703 lumped commit-delta triggers in with drain-time triggers and told a future
implementer both "fail SILENT rather than loud". For drain-time that is right.
For commit deltas it is wrong, and wrong in the direction that matters: it would
send someone to guard the suspended case and ship a trigger that pages about
every idle database.

ag-fixture-builder measured the healthy half while reproducing the never-latch
result. On a quiet but PERFECTLY HEALTHY secondary - SYNCHRONIZED,
is_suspended = 0, secondary_lag_seconds = 0 - last_commit_time sat 1757 seconds
behind wall clock purely because nothing had committed. ag-collector-builder
measured the same thing at ~7 minutes on a separate run. It grows without bound
on an idle database.

So now - last_commit_time fails BOTH ways: it stops growing on a suspended row
(the silent half erikdarlingdata#1703 described) and grows without bound on a quiet healthy one
(the loud half, and the one more likely to actually ship, because it shows up
immediately in testing on any database nobody is writing to). Guarding only the
suspended direction is not enough, so the guidance is no longer "route it
through the gate" but "do not derive lag from commit times at all".
secondary_lag_seconds is the lag measure; the commit times are for showing an
operator WHEN something last happened, not for judging whether it is late.

No logic change - this evaluator has never read those columns. It is the doc
block a commit-delta trigger would be written into, which is exactly why the
guidance in it needs to point the right way.

Their reproduction is also the third independent confirmation of the never-latch
behavior, and more extreme than mine: zero lag across a full 60-second suspend
with the last hardened log ~29 minutes stale, versus ~5 minutes on my run. It
does not depend on how stale the group already was; it simply never latched.

Darling suite green: 3252 passed.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant