Skip to content

A quiet server's job history and default trace watermark read tries the last week before its whole slice (#5515) - #5532

Merged
erikdarlingdata merged 3 commits into
devfrom
fix/5515-event-watermark-fallback
Oct 8, 2026
Merged

erikdarlingdata merged 3 commits into
devfrom
fix/5515-event-watermark-fallback

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Oct 8, 2026 •

Copy link
Copy Markdown
Owner

Fixes #5515

What changed

When the 6-hour watermark probe finds no row, the job_history and default_trace_events reads now try the last seven days before they read the server's whole slice. A quiet server whose newest row is under a week old is answered by seven days of chunks. Only a server quiet for longer, or with no row at all, still pays the unbounded read.

Why

What the code does on current dev, from reading it:

  • The runner already keeps the watermark at write time. ServerWatermarkCache (Cache the server-scoped watermark read across a runner's lifetime (#4197) #4399, merged 2026-09-26) is seeded on the first miss and advanced after each write returns. A quiet server's value, even a null, is cached, so the fallback should run once per service start for each server and collector, not once per cycle.
  • The fallback still runs on any cache miss: a service restart, a server reconnect (OnServerReconnected drops the server's entries), any fault in a run (the catch drops the entry), and the identity-regression branch of job_history. Each one costs a miss, then the 6-hour probe, then the unbounded MAX.
  • The unbounded MAX is the expensive part. job_history's index (server_id, run_datetime DESC) cannot give an ordered chunk scan, because the table is partitioned on collection_time, so the MAX opens every chunk of the server's slice in retention, compressed ones included.

What I infer and could not check: the 13.2-day counters (14,728 and 15,215 calls) likely include days before #4399 and #4209 reached that store, when the unbounded read ran every cycle for every server. ask-5515 has a read-only query that takes two samples an hour apart. A delta near zero means the cache already covers the steady state.

So this PR does not claim to remove every fallback call. It makes each remaining one cheap, and leaves the cache, the reconnect drop and the fault drop alone, since those are deliberate safety rails.

What changes

  • WatermarkPolicy.WidenedWatermarkWindow (7 days) is a new rung after RecentWatermarkWindow (6 hours).
  • GetLastCollectedTimeAsync (default_trace_events and the other timestamp watermarks) and GetLastCollectedInstanceIdAsync (job_history's numeric watermark) run the same bounded statement again with a bound seven days back, and only then the unbounded one. No new SQL text, so the statements keep their pg_stat_statements identity.
  • A hit in the week is never newer than the unbounded MAX, and equals it for every column that rises with collection_time (job_history's instance_id, read as the newest batch's id, and event_time), by the argument RecentWatermarkWindow already makes: the bound is on collection_time, the partitioning column, and a row outside the window cannot hold a newer value than one inside it. The exception is job_history's run_datetime (the job_history watermark): a step is stamped with its start time but written when it ends, so a windowed read can return an older value than the unbounded one. That only widens the caller's re-read, and its natural-key dedupe drops the repeats; nothing is skipped. A miss in the week still falls to the unbounded read, so a null still means no row.
  • Round 1: the cpu_utilization pair read (GetLastCollectedTimeWithFrameAsync) and the per-database read (ReadLastCollectedTimeForDatabaseAsync, used by the Azure deadlock, blocked-process and long-query collectors with no floor) also take the week step now. Before, they went from 6 hours straight to the unbounded read, so a quiet Azure database paid the unbounded read every cycle. Same bounded statement with an older bound, so no new SQL text.

Measurements

From the #5508 audit, step 1 (13.2 days, 43 servers, schema V165):

  • job_history: 14,728 calls at 5,426 blocks each, 79.9 M blocks.
  • default_trace_events: 15,215 calls at 3,758 blocks each, 57.2 M blocks.
  • 3,941 s of execution together.

Rig numbers (a local PostgreSQL 18 store with a few rows, so no block counts): a server whose newest row is two to four days old now issues two bounded reads and no unbounded read for each of the two watermarks. Before, the same server issued one bounded and one unbounded read. A server quiet for 20 days, and one with no row, still issue the one unbounded read and get the same value. The pair read and the per-database read behave the same way on the rig (two bounded reads, no unbounded read, for a newest row two days old).

Test plan

  • New QuietServerWatermarkLadderLiveTests (2 tests, live): the week answers a quiet server with the unbounded value and zero unbounded reads, a new row is picked up by the 6-hour probe in one read, and a server quiet for 20 days or with no row still gets the unbounded answer. The first test fails on the base runner (checked) and passes now.
  • DarlingCollectorRunnerTests, ServerWatermark*, JobHistoryWatermarkEpochLiveTests, TimeHonestyRungTests, plus the Census, Ratchet, Hygiene, Pin, Guard and Scan classes: 1,740 tests in one run, 2 failures, both mine and both fixed. My new class lacked [Collection("live-postgres")], which LivePostgresCollectionHygieneTests requires, and one assertion compared a tick finer than the store keeps. Re-run: the new class, the hygiene class and DarlingCollectorRunnerTests pass (22 tests, 3 skipped by their own gates).
  • No block counts from a store with compressed chunks. The rig has none.
  • Full suite not run on this laptop.

Round 1 fixes

  • Doc and comments (WatermarkPolicy, the runner) no longer say the windowed value is identical: it is never newer than the unbounded MAX, equal when the column rises with collection_time, and job_history's run_datetime is named as the exception (a windowed read can be older, which only widens the re-read; dedupe drops the repeats).
  • The cpu_utilization pair read and the per-database read take the same 7-day step. New live tests count the unbounded reads for each: ThePairRead_OfAQuietServer_... and ThePerDatabaseRead_OfAQuietDatabase_... (a newest row two days old: two bounded reads, zero unbounded; a row 20 days old, or none: one unbounded read, same answer). Both fail with the runner change reverted (checked), pass with it.
  • Rig (local UTC PostgreSQL 18 + TimescaleDB): QuietServerWatermarkLadderLiveTests 4 passed; DarlingCollectorRunnerTests, *DatabaseWatermarkCache* (35), JobHistoryWatermarkEpochLiveTests, PerDatabaseFaultPathSplitTests, QueryStoreAzureTextAndPlanFetchTests, *QueryStoreIntervalWide* (114), *ServerWatermark* (35), TimeHonestyRungTests, *Census* (455), *Ratchet*, *Hygiene* (90), *Pin* (634), *Guard* (330), *Scan* (169), RepoFileAdoptionTests, FleetIdentifierScrubTests, RegisteredServerSettingDriftTests, TsqlConventionGuardTests: 0 failed. Build: 0 warnings.

Changelog

SECTION: Fixed
ENTRY:

…he last week before its whole slice (#5515)

When the 6-hour probe found no row, the read went straight to the unbounded MAX, which
opens every chunk of the server's slice in retention. It now runs the same bounded
statement with a bound seven days back first. The answer is unchanged; a server quiet
for longer than a week, or with no row, still gets the unbounded read.
…d the docs stop calling the windowed value identical (#5515)

job_history.run_datetime does not rise with collection_time, so a windowed read can return an older value than the unbounded one; that only widens the re-read and the natural-key dedupe drops the repeats. The cpu_utilization pair read and the per-database read went from 6 hours straight to the unbounded read; they now try the week first, like the server-scoped read.
@erikdarlingdata
erikdarlingdata marked this pull request as ready for review October 8, 2026 05:27
@erikdarlingdata
erikdarlingdata merged commit 2d6991f into dev Oct 8, 2026
21 of 22 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/5515-event-watermark-fallback branch October 8, 2026 08:46
erikdarlingdata added a commit that referenced this pull request Oct 8, 2026
Adds the changelog entries for the 3.10.0 PRs that merged after the first splice: #5528, #5532, #5537, #5542, #5543, #5552 and #5553. Each full entry goes into docs/changelog/3.10.md and its title-only line into the CHANGELOG.md index. The archive census row for 3.10.0 moves from 257 to 265 entries.

Changelog entries for the 3.10.0 PRs merged after the first splice.
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