Skip to content

After a job-history identity reset, the collector re-reads once instead of on every run (#4487) - #4496

Merged
erikdarlingdata merged 14 commits into
devfrom
fix/job-history-watermark-epoch
Sep 27, 2026
Merged

erikdarlingdata merged 14 commits into
devfrom
fix/job-history-watermark-epoch

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 27, 2026 •

Copy link
Copy Markdown
Owner

Fixes #4487.
Refs #3885.

Why

JobHistoryCollector's identity guard (#3885) already detects when a monitored server's SQL Agent job history has been reset — its own MAX(instance_id) in msdb.dbo.sysjobhistory falls below the id the monitoring store last saw — and falls back to a bounded 24-hour re-read by run_datetime instead of matching nothing forever. Its doc comment promised "one run of fallback per reseed", because the store's own MAX(instance_id) for that server becomes the new, lower maximum on the very next run.

That promise didn't hold, because the store-side watermark reads never stopped returning the all-time maximum id ever stored for a server:

  • Darling's GetLastCollectedInstanceIdAsync (bounded probe over a 6-hour window, falling back to an unbounded MAX) and Lite's equivalent DuckDB read both read the all-time max. The old epoch's rows are retained for a year, so the all-time max stays at the pre-reset number forever, and the guard's regressed arm ran on every cycle, not once.
  • Darling additionally caches this watermark in memory between runs (ServerWatermarkCache). Its Advance rule keeps the greater of the cached and the new batch's value — correct for ordinary incremental progress, but it means a regressed batch's new, lower ids can never pull the cache back down, so once a reseed happens while the service is running, the cache would keep taking the regressed arm even after the store itself had already recovered.

What causes the reseed is not something the collected rows can tell us — a sysjobhistory purge-and-reseed, an msdb restore, or the monitored endpoint moving to a different Availability Group replica (each replica has its own msdb and its own identity sequence) would all look the same from here. sp_purge_jobhistory on its own does not do this: it deletes the oldest rows and does not lower MAX(instance_id).

Measured before cleanup: one production store held 8,970,159 extra copies of 895,439 job runs across 41 servers (up to ~13 copies of a single run); a second held 13,492 extra copies of 120 runs across 10 servers (one run had 245 copies); a third store had none. The stored duplicates on both affected stores have already been removed, separately from this fix. This PR stops new ones from accumulating; it does not touch any already-stored row.

What changes

  • Darling (DarlingCollectorRunner.BuildServerWatermarkInstanceIdSql, GetLastCollectedInstanceIdAsync): both the bounded and unbounded forms now scope the MAX(instance_id) to rows from the server's newest collected batch (an inner MAX(collection_time) subquery), not an all-time max. The run right after a reseed stores the new epoch's ids, so the very next run's newest batch is that epoch's own max, and the guard's regressed arm takes over for exactly one run, as documented.
  • Darling's watermark cache (the post-write step now lives in DarlingCollectorRunner.CommitServerWatermark, extracted unchanged from the run path so it can be tested without a SQL Server): a batch that the collector flags as an identity regression (job_history_identity_regressions = 1, already recorded via context.Measure) now invalidates the cached entry instead of merging it with Advance. The next run re-seeds from the store, which by then holds the new epoch's rows and returns the honest, new max. Ordinary (non-regressed) batches are unaffected — they still advance the cache exactly as before.
  • Lite (RemoteCollectorService.GetLastCollectedInstanceIdAsync): the same newest-batch scoping against DuckDB. Lite has no in-memory watermark cache, so there is nothing else to change there.
  • The failback (A→B→A): no duplicate rows. If the identity later flips back to an epoch this server already stored rows under (a failover away and back, or a reverted restore), the watermark sits at the lower epoch's max after the "away" leg. So the returning epoch's instance_id > @last_instance_id read re-delivers rows that are already stored. Two parts close it:
    • A pre-insert dedupe on the natural key (server_id, instance_id, job_id, step_id, run_datetime). instance_id alone is ambiguous across epochs. A small opt-in contract, INaturalKeyDedupedCollector<TRow> in PerformanceMonitor.Collectors, is implemented only by JobHistoryCollector, so no other collector changes.
      • Darling: DarlingCollectorRunner.WriteBatchAsync reads the batch's own keys back from job_history once, before the COPY and outside its one-retry path, and writes only the rows not already stored. The read is an unnest of the batch's keys joined on those columns, with server_id = $1 AND collection_time >= min(run_datetime) − 1 day. That bound is safe because a row can't be collected before it started, and run_datetime (the target's local clock) is within ±14 h of the store's UTC collection_time. It also lets TimescaleDB skip every older chunk.
      • If the read fails, the batch fails too, and nothing is written that might duplicate.
      • Lite: RemoteCollectorService.WriteBatch does the same DuckDB read before the appender opens. Lite's hot ∪ archive view v_job_history already reads one copy per natural key, so this stops a duplicate reaching the hot table at all.
      • Both sides compare at whole microseconds. JobHistoryCollector.ToMicroseconds truncates the batch rows' run_datetime and the stored keys read back, in Darling and in Lite. PostgreSQL and DuckDB timestamps keep microseconds, while a .NET DateTime can carry 100 ns ticks, so without it a sub-microsecond source time would never match its stored copy. The failback and long-running live tests plant .AddTicks(7) times so this is exercised on every platform.
    • A 7-day lookback on the honest arm: run_datetime >= @min_run_datetime, where @min_run_datetime is the host's already-read newest stored run_datetime minus 7 days. It uses the same sargable shape as the archival-emptied window (an integer run_date pre-filter plus the exact decoded bound). It keeps a failback from re-reading the returning epoch's whole history, and the dedupe drops whatever inside the window is already stored.
      • No second store read: both hosts already read the timestamp watermark.
      • With nothing stored, @min_run_datetime is null and imposes nothing.
      • The one trade: a job step that has been running for more than 7 days when it completes falls outside the window. sysjobhistory stamps a step with its START time but writes the row when it ends.
    • The lookback is capped at the target's own recent past. A future-dated stored run_datetime (a target whose clock was once wrong) would otherwise carry @min_run_datetime into the future, and starve collection until that date. The collector's SQL clamps it to DATEADD(DAY, -7, GETDATE()) on the target's own clock.
  • JobHistoryCollector's doc comment now describes the real mechanism end to end: the host must read the newest batch's max, Darling's cache must invalidate rather than merge on a regressed batch, and a failback is closed by the pre-insert natural-key dedupe, with the 7-day lookback kept for long-running steps. This replaces the previous doc's overclaim and its stated-but-unclosed gap.

Test plan

In-process on macOS against a live PostgreSQL + TimescaleDB, Darling.Tests Release with -p:EnableWindowsTargeting=true.

Live pins, new:

  • JobHistoryWatermarkEpochLiveTests: a server stores an old-epoch batch (ids 10,200,001–10,200,040) and then a newer new-epoch batch (9,545,001–9,545,030).
    • GetLastCollectedInstanceIdAsync returns 9,545,030, both when the newest batch is outside the 6-hour bounded probe (the unbounded fallback) and when both batches are inside it (the bounded path).
    • RED on dev at runtime: it returns 10,200,040, the all-time max.
  • The same class, the failback inputs: batch A (ids 500–520, run_datetime 2026-09-10), then a newer batch B (ids 1–12, run_datetime up to 2026-09-21).
    • The host resolves the numeric watermark 12 and the timestamp watermark = B's newest run_datetime.
    • The job_history query built from them binds @last_instance_id = 12 and @min_run_datetime = that run_datetime − 7 days.
    • Compile-level RED on dev: the bound doesn't exist there.
  • ServerWatermarkCacheRunnerLiveTests.RegressedBatch_InvalidatesTheCache_SoTheNextResolveReadsTheNewEpochFromTheStore: the cache seeded at 10,200,040; a new-epoch batch committed with job_history_identity_regressions = 1.
    • The next resolve returns 9,545,030 by re-reading the store (the timestamp and numeric reads), and the call after it reads nothing.
    • The companion HonestBatch_AdvancesTheCache_WithZeroStoreReads: an ordinary batch still advances the cache with no store read.
    • On dev both fail at runtime, because the method they reach doesn't exist there.
  • ServerWatermarkCacheRunnerLiveTests.Equivalence_JobHistory_CacheMatchesFreshStoreRead_…: its replay batch now carries a HIGHER instance_id than the batch before it (and an older run_datetime), which is the only order a real collector produces. Every arm's batch max is at least the target's current max, and a lower one means an identity reset, which the fact above covers. A comment in the test gives the reason.

Live pins, the failback dedupe (JobHistoryWatermarkEpochLiveTests, through the product's own DarlingCollectorRunner.WriteBatchAsync):

  • WriteBatchAsync_FailbackToAPriorEpoch_StoresZeroDuplicateNaturalKeys: store A1 (ids 500–520, 21 rows), then B (ids 1–12), then the failback batch = A1's 21 rows again + A2 (ids 521–530).
    • Asserts: zero natural-key duplicates, and A2 stored once.
    • RED on dev at runtime AND on this PR's earlier head (the watermark fix without the dedupe): Expected: 10, Actual: 31. Every re-delivered row was stored a second time. This ran as a standalone class that uses only members present on both.
  • WriteBatchAsync_ALongRunningStep_IsStoredOnce_AndDroppedOnReplay: a step row with a run_datetime 5 days old is stored once, and replaying the batch adds nothing.
  • WriteBatchAsync_ASameKeyRowWithADifferentJobIdOrStepId_IsStored: the same instance_id + run_datetime with a different job_id, or a different step_id, is stored. The key is the full tuple.
  • JobHistoryNaturalKeyDedupeTests (pure, 8):
    • JobHistoryCollector implements the contract; the key columns and field order;
    • DropAlreadyStored drops exact tuples only;
    • an empty stored set returns every row; the order is preserved.
  • The read's cost (EXPLAIN, one server, 30 daily chunks with the older ones compressed):
    • a steady-state 50-row batch touches only the 2 newest chunks, 76 shared buffers, ~0.7 ms;
    • a failback batch spanning 7 days touches 8 chunks, 331 buffers, ~2.4 ms.

Lite:

  • LiteJobHistorySourceTests (Darling.Tests, runs everywhere): Lite's GetLastCollectedInstanceIdAsync scopes to the newest batch (collection_time = (SELECT MAX(collection_time) …)), and WriteBatch calls the dedupe before CreateAppender. Both RED on dev at runtime.
  • JobHistoryDedupeAndWatermarkLiteTests (Lite.Tests, real DuckDB; runs on Windows CI, can't run on macOS):
    • after an old-epoch batch and a newer new-epoch batch, the numeric watermark is the new epoch's max;
    • re-writing a half-stored batch appends only the new half, with zero natural-key duplicates.
  • Checked: no existing test drives a job_history write through a fake connection, or counts statements around a write, in a way the new pre-insert read would break (a grep of both test projects).

Mutations, each RED and then reverted:

  • The newest-batch scoping replaced by the all-time MAX → all three JobHistoryWatermarkEpochLiveTests RED.
  • A regressed batch advanced instead of invalidated → Expected 9545030, Actual 10200040.
  • The dedupe made a no-op (it returns every row) → the failback pin RED, Expected 10, Actual 31.

Pure pins:

  • JobHistoryIdentityEpochTests 9/9: the guard's SQL shape with the new @min_run_datetime; the bound derived as the newest stored run_datetime − 7 days, and null with nothing stored; the future-date cap (CASE WHEN … DATEADD(DAY, -7, GETDATE()) in the SQL, the raw value in the parameter).
  • ServerWatermarkReadFloorTests 5/5, ServerWatermarkCacheTests 11/11, ServerWatermarkDispatchGateTests 7/7, DocCommentHygieneTests 77/77.

Totals: JobHistoryWatermarkEpochLiveTests 7/7, JobHistoryNaturalKeyDedupeTests 8/8, LiteJobHistorySourceTests 2/2. ServerWatermarkCacheRunnerLiveTests, JobHistoryIdentityEpochTests, ServerWatermarkCacheTests, DarlingCollectorRunnerTests and DocCommentHygieneTests: 113, 0 failed (3 environment-gated skips). Darling.Tests and Lite.Tests build with 0 warnings. The Lite.Tests facts, and JobHistoryCollectorDefinitionTests (the steady arm's @last_instance_id by name, the first-run and archival arms unchanged), run on Windows CI.

CHANGELOG

SECTION: Fixed
ENTRY:

…all-time max

After a sysjobhistory identity reseed, the target's own MAX(instance_id) drops
below what the store remembers, and the store's all-time MAX never stops being
the higher, pre-reseed number. Darling's and Lite's watermark reads and
Darling's in-memory watermark cache all kept that all-time max, so the
collector's bounded 24h regressed-arm re-read ran every cycle instead of once.

Fixes #4487. Refs #3885.
…ance_id

After a failover away and back (or a reverted restore) to an epoch this server already stored rows under, the newest-batch watermark fix alone was not enough: the incremental read still had no time bound, so it could re-collect every already-stored row from the returning higher epoch. The steady-state arm now also requires run_datetime >= a host-supplied floor (the newest stored run_datetime minus 7 days), composed the same sargable way as the existing archival-emptied window. The cost: a job step running longer than 7 days is missed by this bound, since sysjobhistory writes a step row only when the step ends.
…ct's real batch ordering (#4487)

The equivalence pin planted a replay batch whose instance_id (50) was
lower than the prior batch's (102), which the #4487 newest-batch
numeric-watermark scoping correctly treats as an identity regression
and no longer merges into the cache the way a plain MAX did before.
No real collector arm can produce a newest batch with a lower max
than an earlier one (the steady arm reads only ids above the current
watermark; the regressed and archival-emptied arms re-read a window
bounded by the target's own current max; the first run reads
everything), so this shape was never reachable in the product -
only in this test's own data.

The replay batch now keeps its older run_datetime (proving the
timestamp watermark still does not move backwards) while raising its
instance_id above the prior batch's, matching how a real batch would
look. The regressed-batch shape (a genuinely lower newest-batch max)
already has its own coverage in the pure ServerWatermarkCache tests
and the runner's invalidate-on-regression wiring.
…Watermark

Moves the regressed-vs-honest branch that runs after a batch write
(invalidate the cache on an identity regression, else advance it) out
of RunCoreAsync's plain write path and into its own
CommitServerWatermark<TRow> method, called from the same spot under
the same guard. Behaviour-preserving; the #4487 comment moved with it.

Adds two live pins to ServerWatermarkCacheRunnerLiveTests: a regressed
batch invalidates the cache so the next resolve re-seeds from the
store and reads it exactly once, and an honest batch still advances
the cache with zero store reads.
A failover and failback re-reads up to 7 days of a returning epoch's
job_history rows on purpose (long-running steps, clock skew). Until now
that honest re-read landed as duplicates: the numeric watermark alone
cannot see a returning epoch's own already-stored rows.

Both hosts now read the batch's own natural key (server, instance_id,
job_id, step_id, run_datetime) back from the store once before the
write and drop any row already stored under either epoch. instance_id
alone is ambiguous across an epoch that returns, so the key is the
full tuple. The 7-day lookback itself is unchanged.

Darling: DarlingCollectorRunner.WriteBatchAsync reads the keys with one
statement bounded on collection_time (chunk exclusion), before the
#3099 retry loop, so a retry never re-reads. Lite: WriteBatch does the
same keyed read against DuckDB before the appender opens.

The contract (INaturalKeyDedupedCollector) is opt-in; only
JobHistoryCollector implements it, so no other collector's write path
changes.
Source-scan pins (macOS) prove the numeric watermark read is scoped to
the newest batch and the pre-insert dedupe runs before the appender
opens, both RED against the pre-fix text on dev. Real-DuckDB facts
prove the newest-batch scope and the dedupe's effect on a real batch
write; they build but cannot run on macOS.
The in-memory natural-key dedupe compared DateTimes exactly, so a batch
row's RunDateTime (100 ns ticks on Windows, whole microseconds
elsewhere) never matched a stored key read back from PostgreSQL or
DuckDB (both microsecond precision), and the dedupe dropped nothing.

JobHistoryCollector.GetNaturalKey and both stored-key reads (Darling
and Lite) now truncate through one ToMicroseconds helper before the
comparison.
@erikdarlingdata
erikdarlingdata marked this pull request as ready for review September 27, 2026 21:22
@erikdarlingdata
erikdarlingdata merged commit 583f9fe into dev Sep 27, 2026
17 of 18 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/job-history-watermark-epoch branch September 27, 2026 21:22
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