AG latency: commit-time columns, drain-time estimates, primary-side perfmon counters (#991)

[erikdarlingdata]

Implements the three plan addenda on top of #1688, and corrects a doc claim that #1688 shipped and a live AG has since disproved.

Stacked on #1691 (still open at time of writing), so the diff shown here includes that PR's commits until it merges.

1. Four commit-time columns

ag_database_replica_states gains last_commit_time, last_hardened_time, last_redone_time, last_received_time — the four timestamps from the same DMV that the reference project's query skips. They matter because, unlike secondary_lag_seconds, they are directly comparable across replicas: primary-vs-secondary commit-time lag is a subtraction between two rows rather than a number one replica self-reports.

2. Two drain-time estimates, computed server-side

est_redo_completion_time_min = CONVERT(float, (hdrs.redo_queue_size * 1.0 / NULLIF(hdrs.redo_rate, 0)) / 60.0)
est_send_drain_time_min      = CONVERT(float, (hdrs.log_send_queue_size * 1.0 / NULLIF(hdrs.log_send_rate, 0)) / 60.0)

Three deliberate choices, each pinned by test:

• * 1.0 — without it this is BIGINT ÷ BIGINT, so a 0.4-minute drain floors to 0, i.e. "already drained". Silent and wrong.
• NULLIF(rate, 0) — an idle, caught-up or suspended replica has rate 0. Without the guard that is a divide-by-zero that fails the entire collection cycle, not one column.
• CONVERT(float, ...) — the unconverted expression comes back numeric, and GetDouble throws on a decimal. This is the difference between a column that works and one that throws on every row with data.

NULL means "no drain rate" (idle / suspended / caught up) and is never coerced to 0 — 0 would read as "drains instantly", the exact opposite of the truth.

Computed per row at the sample's own instant rather than composed later as a queue/rate ratio, because a ratio of two window aggregates (avg queue ÷ avg rate) is not the average of the per-sample ratios, and the two diverge worst precisely when rates swing — which is when someone is looking. Both are registered as Gauge compose measures (duration family, native minutes) so they chart directly.

3. Two primary-side perfmon counters

Transaction Delay and Mirrored Write Transactions/sec join PerfmonStatsCollector's existing whitelist. Their ratio is the average primary-side commit delay per mirrored transaction — the primary half of a picture the ag_database_replica_states gauges only cover from the secondary side. Zero new schema; they ride perfmon_stats.

Verified live rather than assumed (SQL2022, no AGs configured):

counter_name                       object_name                   occurrences
---------------------------------- ----------------------------- -----------
Mirrored Write Transactions/sec    SQLServer:Database Replica              1
Transaction Delay                  SQLServer:Database Replica              1

Three things that check out: both counters exist even with Always On unconfigured, both sit on SQLServer:Database Replica, and each occurs exactly once server-wide — so the collector's counter_name-only filter genuinely cannot collide with another object's counter, which is the assumption the no-object_name-predicate design rests on.

Per the addendum, no action needed on HADR_SYNC_COMMIT — it already flows through wait_stats. With these three pieces, sync-commit pressure is now composable end to end: primary-side delay, secondary-side queues and rates, drain estimates, and the wait itself.

4. A doc claim from #1688, corrected against a live AG

@ag-fixture-builder validated both queries against a Docker AG fixture and found one of my doc comments contradicted by the instance. #1688 restated MS Learn faithfully:

This value shows as 0 if the data movement is suspended.

The live instance (SQL Server 2022 16.0.4265.3, CLUSTER_TYPE = NONE) does the inverse, measured across a 60-second SUSPEND_FROM_USER on the primary's remote row under write load:

sample	is_suspended	sync state	secondary_lag_seconds
active, caught up	0	SYNCHRONIZED	0
+15s suspended	1	NOT SYNCHRONIZING	15
+30s suspended	1	NOT SYNCHRONIZING	31
+45s suspended	1	NOT SYNCHRONIZING	46
+60s suspended	1	NOT SYNCHRONIZING	62
after RESUME	0	SYNCHRONIZED	0

It reads 0 when movement is active and caught up, and accrues monotonically once suspended. So the risk #1688 documented — a suspended replica hiding as zero lag and under-reporting the worst case — does not exist: a lag threshold fires on its own. Reading is_suspended alongside is still right, but to explain why lag is climbing, not to catch lag that is masked.

The comment now describes measured behavior and flags the doc as unreliable, with the caveat that this is one build and a clusterless AG (WSFC untested). Two further measured facts are now documented in the collector:

• log_send_queue_size goes NULL while suspended, while redo_queue_size freezes at its last value — so a redo-queue reading on a suspended replica is stale, not current. (The WritePayload test now models exactly this: a 62-second-suspended replica with a null send-drain estimate.)
• Collecting from a SECONDARY yields a one-row self-view. sys.dm_hadr_* carries only the local replica's rows there, so the INNER JOIN narrows to one row even though sys.availability_replicas holds every replica. A complete AG picture requires collecting from the primary.

The compose-measure comment claiming the same doc behavior is corrected too. The suspension-state dimensions #1691 added stay — they are still the right call, now for the corrected reason.

Migration: V36, appended, not a V34 edit

The obvious shortcut — widen V34's CREATE TABLE since it is unreleased — is a trap. CREATE TABLE IF NOT EXISTS is a no-op on a store that already ran V34, so editing it would leave every already-migrated store (the field box included) six columns short while fresh installs got them. V36 does ALTER TABLE ... ADD COLUMN IF NOT EXISTS, which appends physically in the same order PgSchemaGenerator emits, so both provenances end up identical.

That broke the shape pin I added in #1691 (V34's CREATE no longer equals the generator's output, correctly). Rather than weaken it, the pin now reconstructs: it generates the historical 15-column shape via a TruncatedSchema wrapper and asserts V34 matches that exactly, then asserts V36 appends the remaining columns in order with the generator's own types. Together those prove fresh == upgraded.

Both failure modes confirmed by planted defects, not assumed:

• est_send_drain_time_min real instead of double precision in V36 → red.
• widening V34 in place with last_commit_time → red.
• restored → green.

Version 36 rather than 35 because 35 is claimed by the concurrent AG-alerts work (pm-991a); I confirmed that directly and messaged @ag-alerts-builder so neither of us stalls on the other.

THIRD_PARTY_NOTICES.md

Hannah Vernon's SqlServerAgMonitor now has its own section, following the file's existing per-component format (Author / Repository / License, usage sentence, ### License Text with the MIT body pulled verbatim from the clone's LICENSE, and a full-license link), plus a line in Acknowledgments. The collector-header attribution from the original brief stays — both belong.

Tests

Lite.Tests      1495 passed, 0 failed
Darling.Tests   3215 passed, 0 failed (155 skipped - the live-Postgres gated set)
Solution build  0 warnings, 0 errors

New/extended: the drain-estimate guard pin (both expressions verbatim + the CONVERT(float, wrapper), the widened payload-order and type pins, ReadAsync mapping and null-tolerance for all six columns, the V36 migration identity pin, the V34+V36 reconstruction pin, the perfmon counter-list pin (59 → 61), and the AG measure count (5 → 7).

Installer.Tests not run (live-DB categories clobber real Agent jobs on SQL2022).

Live smoke — SQL2022, no AGs

The widened query, extracted programmatically from the collector's QueryText constant so it is provably what ships, run verbatim:

ag_name  database_name  replica_server_name  is_local  synchronization_state_desc  last_hardened_lsn
last_commit_lsn  log_send_queue_size  redo_queue_size  log_send_rate  redo_rate  is_suspended
suspend_reason_desc  availability_mode_desc  secondary_lag_seconds  last_commit_time
last_hardened_time  last_redone_time  last_received_time  est_redo_completion_time_min
est_send_drain_time_min
(0 rows affected)
EXIT=0

All 21 columns resolve — including the two computed expressions, which is the real thing being checked here since a malformed CONVERT/NULLIF would fail at parse.

🤖 Generated with Claude Code