Repository navigation
Darling: the raw procedure duration trend reads per-collection totals, written with each procedure_stats batch (#5638) - #5706
Conversation
… from the server's floor, procedure_stats rows below it (fixes #5638)
| /// <see cref="DarlingTrendReader.ShouldUseRawTier"/> (#2353) measures against the wall clock because retention drops by age, | ||
| /// so the clock is one <paramref name="wallClock"/> reading (the real clock unless a test passes one). | ||
| /// </summary> | ||
| internal static DateTime TierClock(string? asOf, DateTime windowEndUtc, Func<DateTime>? wallClock = null) => |
There was a problem hiding this comment.
The Viewer's chart keeps the exact bug this fixes. TierClock pins the clock for the two MCP tools, but the Viewer's procedure/query duration charts resolve their tier through a second, independent DateTime.UtcNow and were not touched:
ViewerServerTab.TimeRange.cs:130—GetWindowUtc()callsViewerTimeRangeWindow.Window(RangePicker.Value, DateTime.UtcNow, …), and a live relative range returnsEndUtc = nowUtc,StartUtc = nowUtc - span(ViewerTimeRangeWindow.cs:33-43).ViewerServerTab.Queries.cs:136→LoadPerformanceTrendsAsync(startUtc, endUtc)→ViewerServerTab.QueryTrends.cs:83-84callGetQueryDurationTrendAsync/GetProcedureDurationTrendAsyncwith nonowUtc.ViewerDataService.QueryTrends.cs:517-519then doesawait GetRollupAvailabilityAsync(…)and only afterwardsDurationTrendRouting.ResolveTier(startUtc, nowUtc ?? DateTime.UtcNow, …)— a clock read after an awaited store round-trip, i.e. the same "a few milliseconds LATER" this doc comment describes, and with a wider gap than the MCP path had.
So for a live window of exactly 95 h (TimescaleSupport.RawRetentionSpan - DurationTrendRouting.RawTierMargin), ShouldUseRawTier(startUtc, nowUtc) at DurationTrendRouting.cs:78-79 evaluates now₁ - 95h >= now₂ - 95h with now₂ > now₁ → false → the Viewer serves the hourly tier where get_procedure_duration_trend now serves raw. The range is reachable: TimeRangeParser.cs:123 accepts h/hr/hour(s) and TimeRangePresets.FromHours accepts any positive value, so "past 95 hours" is a live spec.
That makes the two surfaces answer the same question from different tiers — the #3684 shape ViewerTrendRoutingPortTests exists to prevent ("Two copies of one definition pinned EQUAL to each other fail only after BOTH have drifted"). The viewer side is unpinned: A95HourWindowWithNoAsOf_RoutesRawEveryTime only exercises DarlingTrendReader.Resolve*DurationTrendRoute.
The fix is the same one-liner on the viewer side — pass the window's own end as the clock for a live range (and keep the wall clock for a fixed/finished one, where IsLive is false and the end really is an anchor in the past, matching TierClock's as_of arm). Please either do that, or say in the PR body that the Viewer keeps the old clock deliberately so the divergence is on the record.
| Assert.DoesNotContain("SAVEPOINT", between, StringComparison.OrdinalIgnoreCase); | ||
|
|
||
| /* collect.procedure_stats has exactly one writer: the runner's COPY. */ | ||
| foreach (var file in new[] { "DarlingWorker.cs", "DarlingRetention.cs" }) |
There was a problem hiding this comment.
Non-blocking. The whole stitch rests on "every collection at or after the floor has a totals row", and the only thing standing behind it is this two-file roster — exactly the #3699 shape in .github/REVIEW-TRAPS.md: "A roster-based census does not see the file it does not roster … An anti-pattern census sweeps the class (every tool body); rosters are for the positive contract only." A third service file that acquires an INSERT INTO collect.procedure_stats (or a BeginBinaryImportAsync naming it) passes here, and the consequence is not a loud failure: a collection at or after the floor with rows but no totals row drops out of stored, the collection_log axis re-adds it through the points idle arm, and it plots as a measured 0 — the fabricated-zero shape the three-state contract exists to prevent.
I checked by hand and the claim holds today: the only other BeginBinaryImportAsync call sites are Targets/RdsDeadlockIngestor.cs:424, RdsLogEventIngestor.cs:303, RdsPlanIngestor.cs:323 and RdsCpuIngestor.cs:582, all on pg_* tables, and CopyBatchOnceAsync is the single procedure_stats writer. Worth sweeping the directory rather than naming two files, so the next writer fails here instead of in a chart.
|
Two smaller notes from the blind read, neither blocking. 1. This is a pre-existing gap, not one the PR opens: V164/V165/V167/V170 use the same 2. Things I could not check from a read-only tree, for whoever runs the rig: every live pin here is I also traced the retention ordering by hand and it holds in the safe direction: |
There was a problem hiding this comment.
Verdict: CHANGES REQUESTED
Reasoning for both findings is in the inline comments and the top-level note; this is the ledger.
Claims
- VERIFIED — grain, column types,
NULLS NOT DISTINCTkey, time index —ProcedureStatsTotals.cs:56-68 - VERIFIED — no backfill, three idempotent DDL statements — same hunk;
MigrationDataMovingRungCensusPinsreads resolvedScripts, so it does see V176 and has nothing to declare - VERIFIED — upsert on the COPY's transaction, after the COPY/dimension flush, before the commit, no savepoint, no catch, chosen by
TargetTable—DarlingCollectorRunner.cs:4455-4458,:4468,:4482-4487 - VERIFIED — recomputes never adds; zero-row batch writes nothing —
ProcedureStatsTotals.cs:86-94,ProcedureStatsTotalsWriter.cs:44-47 - VERIFIED — one writer for
procedure_stats— the other fourBeginBinaryImportAsyncsites are RDS ingestors onpg_*; fan-out:2833and re-attempt:4417both reachCopyBatchOnceAsync - VERIFIED — retention at
procedure_stats' effective days, never before raw of that age —DarlingRetention.cs:1007-1019;TimeSlicedDeleteSql:1293-1301splicesPrunePredicateinto theWHEREand bothmin()anchors, so the anchor is the oldest deletable row and the loop cannot spin - VERIFIED — version bump chain —
StorageVersion.cs:19,ViewerDataService.cs:1185,:1888,:1909-1912 - VERIFIED — no GRANT needed —
DarlingManagedRoles.cs:1203; BYOALTER DEFAULT PRIVILEGESfor admin/viewer/mcp atDarling/tools/provision-roles.sql:1164-1180 - VERIFIED — no collection read from both arms — floor is
MIN(collection_time)for$1so all totals are at or after it; rows arm strictly<;COALESCE(…,'infinity')sends a totals-less server wholly to the rows - VERIFIED — measures and NULL semantics match the rows arm —
SUM/MAXignore NULLs; the four UNION ALL columns share types and order (::bigintmatchingCOUNT(*) FILTER), names come from arm 1, and a NULLdatabase_namefails= ANY($4)on both, so the three-state contract andmatched_rowssurvive - VERIFIED —
runs/events/sequenced/points/gapped/rawand thecollection_logaxis untouched; all readers alias one builder (ViewerDataService.QueryTrends.cs:162,DarlingTrendReader.cs:1173) - VERIFIED —
TierClockis one clock per call, the window end with noas_of, routing 95 h Raw; no Lite twin —DarlingMcpTrendTools.cs:108/:569/:656vsDurationTrendRouting.cs:78-79; Lite is DuckDB with no tier (LocalDataService.TrendBuckets.cs:352) - UNVERIFIED — "560-1,060 rows per collection, ~60 K heap pages per 24 h read" — live measurement
- UNVERIFIED — the
EXPLAINtable, incl. runtime chunk exclusion and the floor index at 1 vs 40 servers — needs the PG 18.6 / TimescaleDB 2.30.1 fixture - UNVERIFIED — "the read-back uses an index" — asserted but behind
Assert.SkipWhen(DARLING_TEST_PG empty) - UNVERIFIED — every test count (16, 83, 674, 1,243, the 1,464 sweep) and
0 Warning(s); the author states the full suite and full post-fix sweep were not re-run - UNVERIFIED — the 120-comparison oracle; its arithmetic self-asserts but it is live-gated, so the equivalence argument is unexercised here
- UNVERIFIED — "revert-proof:
<= floorfails the straddling windows" — needs the rig - REFUTED — one writer "pinned by a source test on the other service files": the fact is true, the pin is not.
ProcedureStatsTotalsTests.cs:105-109reads two named files for one literal; no third file, noBeginBinaryImportAsync, noUPDATE
Riskiest lines
DurationTrendRouting.cs, the rows arm'sAND collection_time < (SELECT floor_time FROM totals_floor)— a collection at or after the floor with rows but no totals row leavesstored, returns via thecollection_logaxis as an idle point and plots a measured 0, silently. I could not reach it (one writer, onestoredCollectionTimeper batch at:4530/:4592, sequential batches, retention ordered safely) — pinned byProcedureTrendTotalsStitchLiveTests.TheStitchedStatementReturnsTheBucketsTheRowsOnlyStatementReturns, live-gatedDarlingCollectorRunner.cs:4482-4487— no savepoint/catch, so a fault costs the batch's sample thatStoreWriteReattemptdeclines to re-run — pinned byAFailedTotalsUpsert_AbortsTheBatch_…(live-gated); position only byTheRunner_WritesTheTotalsOnTheCopysTransaction_…Mcp/DarlingMcpTrendTools.cs:108— fixes the MCP surface only — pinned byA95HourWindowWithNoAsOf_RoutesRawEveryTime; the Viewer twin atViewerDataService.QueryTrends.cs:517-519is UNPINNED and unfixed
Traps near this diff
- "A NEW delta column needs an interval beside it and
IS DISTINCT FROM 0in the aggregates that roll it up." — applies, satisfied (ProcedureStatsTotals.cs:62; the read keepsCASE WHEN is_stored AND max_interval_seconds = 0 THEN NULL) - "
CASE WHEN interval > 0 THEN delta / interval ELSE 0 ENDspells 'unknowable' as 0 … End atEND(NULL)." — does not apply (DurationTrendRouting.cs:600-605, outside the diff, still ends atEND) - "Any
a / bover integer columns is suspect until a1.0 *or a CAST is found." — does not apply:SUM(total_elapsed_time) / 1000.0is numeric/numeric - "A
total_*assigned from a.Countis a count of the page unless the set is provably whole." — does not apply:row_countis SQLCOUNT(*)over the whole row-group (ProcedureStatsTotals.cs:85) - "
hours_back,limit,top,days_backare refused when out of range, never clamped." — does not apply: the clock moved, not the validator (McpHelpers.cs:241-252) - "Two copies of one definition pinned EQUAL to each other fail only after BOTH have drifted (#3684). Alias, do not copy." — applies: the SQL is aliased, the tier clock is not (
ViewerDataService.QueryTrends.cs:517-519) - "Lite and Darling ship in parity … a fix to one SKU's reader, tool, alert or description without the counterpart's is a finding, not a nit." — does not apply: PostgreSQL-only storage change, identical payload, Lite has no tier (
LocalDataService.TrendBuckets.cs:352) - "A roster-based census does not see the file it does not roster … rosters are for the positive contract only." — applies twice: the one-writer pin names two files (
ProcedureStatsTotalsTests.cs:105), andStoreSelfMetricsTests.PlainCollectTableCensus_…:363-371regexesPgMigrations.csliterals only, so it is blind to V176's DDL atPgMigrations.cs:1006; the second is pre-existing (V164, V170)
Divergence (blind read vs PR body)
The body states the clock defect surface-neutrally — "the MCP duration-trend tools' tier decision, which read a second clock a few milliseconds after the window was computed" — then fixes the MCP tools alone. The Viewer's duration charts have the identical two-clock shape with a wider gap (ViewerServerTab.TimeRange.cs:130 reads DateTime.UtcNow; ViewerDataService.QueryTrends.cs:517-519 reads it again after await GetRollupAvailabilityAsync(…)), and a live 95-hour range is reachable through the picker (TimeRangeParser.cs:123, TimeRangePresets.FromHours). The Viewer's clock appears nowhere in the body — not fixed, not deferred, not out of scope — while "Lane B" is explicit that the Viewer and web charts share the statement with no caller change. That is the blocking item: the two surfaces now answer the same 95-hour question from different tiers.
Smaller: the one-writer claim cites a pin that does not assert it (REFUTED above), and the doc added to DurationTrendRouting.cs says the floor predicate means "TimescaleDB excludes chunks past it", which the body's own EXPLAIN table contradicts for the after-the-floor window. Everything else matched the diff.
Reviewer checklist
- With
DARLING_TEST_PGset, runProcedureTrendTotalsStitchLiveTests,ProcedureStatsTotalsWriterLiveTests,DurationTrendDatabaseFilterLiveTests— the equivalence, atomicity, index and retention-ordering argument is entirely live-gated -
EXPLAIN (ANALYZE, BUFFERS)the rows arm on a real TimescaleDB store for a window after the floor; confirm the per-chunk probes stay cheap rather than growing with the store, then reconcile the "excludes chunks past it" sentence - Time a retention sweep on a large store:
PrunePredicaterunsmin(collection_time) FROM collect.procedure_statsthree times per slice statement - Open the Viewer on a V176 store at a live "past 95 hours" and compare the Procedure Duration chart's tier against
get_procedure_duration_trend(hours_back: 95) - Watch a real cycle on an Azure SQL DB target (
ProcedureStatsCollector.cs:691): each database's batch re-reads the collection's growing row set - Confirm a fresh install and a V175 to V176 upgrade leave viewer/MCP roles able to
SELECT collect.procedure_stats_totals— this read fails hard (42P01/42501), not gracefully
…nce, read-back limited to the batch's databases, rollback gap totalled, retention tests on compressed chunks (part of #5638)
There was a problem hiding this comment.
Verdict: LGTM
Claims
- VERIFIED —
PrunePredicateis nowcollection_time < COALESCE($2::timestamp, $1), the floor passed as a parameter instead of an inline subquery —ProcedureStatsTotals.cs:197 - VERIFIED —
MeasureRawFloorAsyncreads the earliest chunk'srange_startfromtimescaledb_information.chunkswhen Timescale is available, else onemin(collection_time)—ProcedureStatsTotals.cs:207-225; pinned byOnTimescaleDb_WithACompressedOldestChunk_...and the plain-PG retention test - VERIFIED — the floor is threaded through a new
secondParameteronPurgeOneAsyncand bound to the procedure_stats_totals DELETE, with the purge skipped (and counted failed) when the floor can't be measured —DarlingRetention.cs:1018-1053 - VERIFIED —
UpsertSqlgained$3/$4to limit the read-back to the batch's own databases (database_name = ANY($3) OR ($4 AND database_name IS NULL)) —ProcedureStatsTotals.cs:105; exercised live byPerDatabaseBatchesAtOneCollectionTime_TotalOnlyTheirOwnDatabases_AndStayExact - VERIFIED —
GapFillSqltotals every collection strictly after the server's newest earlier totals row and strictly before the batch, recomputing via the same upsert target —ProcedureStatsTotals.cs:118-148; pinned by the stitch-trend live tests and the text pin inProcedureStatsTotalsTests - VERIFIED — the gap fill now runs behind a savepoint (
pst_gap) and a server-sidestatement_timeout(half the command timeout, floor 1s), and a fault rolls back to the savepoint, logs a warning, and lets the batch's own upsert (still bare, still fatal) proceed —ProcedureStatsTotalsWriter.cs:112-180; pinned byAFailedGapFill_DoesNotFailTheBatch_AndTheNextBatchDoesNotRetryItandAGapFillThatTimesOut_IsCancelledByTheServer_... - VERIFIED — on success the prior
statement_timeoutis restored (read in the same round trip as the anchor) before the savepoint is released, sinceRELEASE SAVEPOINTdoes not itself undo aSET LOCAL/set_config(..., true)made inside it — matches Postgres subtransaction semantics; pinned byTheGapFill_TotalsARealGap_LogsNothing_AndRestoresTheStatementTimeout - VERIFIED — the read-back limit's type check was replaced by
ProcedureStatsTotalsWriter.DatabaseNamesOf, which accepts anyIEnumerable<ProcedureStatsCollector.Row>rather than onlyList<Row>—ProcedureStatsTotalsWriter.cs:53-61,DarlingCollectorRunner.cs:4698-4703; pinned byTheReadBackLimit_MatchesEveryRowCollectionShape_...andTheReadBackLimit_ReachesTheWriter_OnTheRunnersOwnPath - UNVERIFIED — the EXPLAIN (ANALYZE, BUFFERS) numbers quoted for the normal gap-fill probe (2 buffers / 0.135 ms, no Seq Scan) — a live measurement, not checkable from a read-only tree
- UNVERIFIED — the reported local test run counts (271 tests, 0 failures) and "proven against the old shape: with the catch arm made to rethrow, both fault tests fail" — both are claims about runs performed by the author, not reproducible statically
Riskiest lines
Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs(TryGapFillAsynccatch block, rollback→release→log sequence) — this is the load-bearing "can never fail the batch" guarantee; a slip here (e.g. not rolling back before the batch's own upsert runs) would reintroduce the original defect — pinned byAFailedGapFill_DoesNotFailTheBatch_AndTheNextBatchDoesNotRetryItDarling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotalsWriter.cs(SetStatementTimeoutAsyncrestore-then-release ordering around the gap command) — wrong ordering would leak the shortened timeout into the batch's own upsert — pinned byAGapFillThatTimesOut_IsCancelledByTheServer_LogsTheRange_AndTheBatchStillCommits(assertsstatement_timeoutis back to the original inside the same transaction after a rollback) andTheGapFill_TotalsARealGap_LogsNothing_AndRestoresTheStatementTimeout(success path)Darling/PerformanceMonitor.Darling.Storage/ProcedureStatsTotals.cs(GapFillSql's correlated anchor subquery, NULL-anchor boundary) — a server with no totals row at all must total nothing (the raw trend arm covers it instead); getting this backwards would either backfill history that belongs to the raw arm or silently drop the server's first batch — pinned byAServerWithNoTotalsYet_IsNotBackfilledByTheFirstBatch_AndTheTrendStillEqualsTheOldStatementandACollectionAnOlderBinaryWroteAboveTheFloor_IsTotalledByTheNextBatch_AndTheTrendEqualsTheOldStatement
Traps near this diff
chunk_compression_statsreturns ZERO rows for a hypertable whose compression is off, so a chunk count over it reads 0 (#3610) — does not apply:MeasureRawFloorAsyncreadstimescaledb_information.chunks, notchunk_compression_stats, and the live test exercises exactly the compressed-oldest-chunk case (OnTimescaleDb_WithACompressedOldestChunk_...) —ProcedureStatsTotals.cs:214- Lite and Darling ship in parity: a fix to one SKU's reader/writer without the counterpart is a finding (#3594) — does not apply:
procedure_stats_totalsand its gap fill are Darling-Postgres-only constructs with no DuckDB analogue in Lite (confirmed bygrep -rl ProcedureStatsTotals Litereturning nothing), and the PR body states this explicitly; not a parity gap introduced by this diff
Divergence (blind read vs PR body)
None — the body's "Review round 1" and "Review round 1 follow-up (seat)" sections both match what the diff does: the floor-as-parameter change, the per-database read-back limit (narrowed first to a List<Row> type check in 4e60c5be2, then widened to DatabaseNamesOf in ff0bd67d3, exactly as the follow-up section describes), the gap fill's savepoint/timeout wrapping, and the test additions all line up with the stated mechanisms.
Reviewer checklist
- Run the live Postgres/TimescaleDB test rig (
DARLING_TEST_PG) forProcedureStatsTotalsWriterLiveTestsandProcedureTrendTotalsStitchLiveTests, including the two new fault-injection tests (refusing trigger, sleeping trigger) and the compressed-chunk retention test, since none of this can be executed from a read-only tree
…wn time, an empty gap costs one probe, the anchor is a bound parameter, the plain floor is an index probe per server and runs after the budget gate; V176 compose-stamp probe pin (part of #5638)
Claude posting for Erik Darling. All four findings are answered on later commits. (1) Rows-arm zero for a collection with rows but no totals: the gap fill (4e60c5b, ff0bd67) totals every collection between the newest totals row and the batch, verified in the LGTM review at ff0bd67. (2) Bare upsert with no savepoint: intended, so totals and raw rows commit or fail together; the gap fill, the part that can be slow, runs behind savepoint pst_gap with a statement_timeout and never fails the batch. (3) Viewer tier-clock twin: a pre-existing millisecond skew this PR does not introduce, filed as #5725. (4) REFUTED one-writer pin: fixed in 061989f, which scans every Darling source file and was shown to fail on a planted writer.
Claude posting for Erik Darling.
Fixes #5638. Two lanes, one PR: Lane A built the write side (table, writer, retention, MCP clock), Lane B the read side (the raw trend reads the totals; see
## Lane Bbelow).Why
The raw procedure duration trend sums every row of every collection from
procedure_stats(about 560 to 1,060 rows per collection per server since #5463), so a first 24 h read touches about 60 K heap pages. Erik's plan (issue comment, 2026-10-09): the collector writes per-collection totals in the same transaction as the procedure rows, and the trend reads them. The same plan fixes the MCP duration-trend tools' tier decision, which read a second clock a few milliseconds after the window was computed.What changes
Table and key (V176,
procedure-stats-totals).collect.procedure_stats_totals, grain(server_id, collection_time, database_name), same column types asprocedure_stats, no unit conversion:Unique index
ux_procedure_stats_totals (server_id, collection_time, database_name) NULLS NOT DISTINCT, plusix_procedure_stats_totals_time (collection_time)for the retention slice. No backfill: the rung isCREATE ... IF NOT EXISTSonly and moves no row.NULL database_name.
procedure_stats.database_nameis a nullabletext, so the key isNULLS NOT DISTINCT(V170 already uses the form, so PostgreSQL 15 is the floor). The NULL database is one group, as GROUP BY makes it, and the upsert's conflict target matches that index. The totals keep the NULL group exactly as the raw rows have it.Write path.
ProcedureStatsTotalsWriter.UpsertBatchAsync(new, Storage), called fromDarlingCollectorRunner.CopyBatchOnceAsyncfor procedure_stats batches only (chosen bydefinition.TargetTable, like the ledger), on the COPY's own transaction, after the COPY and the dimension flush, before the commit, no savepoint and no catch around the upsert itself (the gap fill ahead of it is the exception, see "Review round 1 follow-up (seat)"). A fault in the upsert throws out of the batch, the transaction rolls back, and the raw rows are not stored, so rows and totals commit together or not at all (live-tested). The statement reads back the rows the store holds for(server_id, collection_time)and upserts one row per database, setting every measure fromEXCLUDED, so it recomputes and never adds: a second batch at the same collection_time, or a re-attempt, is exact. A batch with zero rows writes no totals row and costs no round trip (the read keeps its collection_log axis for an idle run).procedure_statshas exactly one writer, the runner's COPY (pinned by a source test on the other service files). EXPLAIN on the local test store shows the read-back using an index (functional check only; no performance numbers are claimed).Registration, both store kinds. A plain table, not a hypertable, not a collector (not in
CollectorCatalog.All): about one row per database per collection against a thousand raw rows, the same class as the V164 ledger and the V170 rollup. It sits incollect, so the blanket SELECT and owner default privileges cover it; no provisioning change. Chunk interval and compression do not apply. Retention (DarlingRetention) is a time-sliced DELETE atprocedure_stats' own effective days (EffectivePurgeRetentionDays, so a per-collector override moves both) on both store kinds.ProcedureStatsTotals.PrunePredicateadditionally keeps every totals row at or after the oldestprocedure_statsrow, because on TimescaleDB the raw chunks leave through the gated purge, which can hold them past the horizon: a totals row is never purged before the raw rows of its age. Version bump chain done:StorageVersion176, the Viewer probe sentinel plusMapProbedSchemaVersionarm andGetBooleancall, and the older-rung tests (probe ordinals, rung ladder,CaggGroupIndexDropLiveTestsartifact drop).MCP clock fix.
get_query_duration_trendandget_procedure_duration_trendnow passnowUtc: TierClock(as_of, now)as well aswindowEndUtc.as_ofdoes NOT choose the tier: withas_ofthe tier is still judged against the wall clock (retention runs on the wall clock, so the raw tier is whatever the store still holds now), using the singleDateTime.UtcNowthe tool already took. Withoutas_of, the window end is used as the tier clock instead of a secondUtcNowread, so a 95 h window (start exactlyRawRetentionSpan96 h lessRawTierMargin1 h before its end) always routes Raw (ShouldUseRawTier, #2353). ThewallClockparameter is the test seam.Test plan
Local rig: PostgreSQL 18 + TimescaleDB,
DARLING_TEST_PGset, built with0 Warning(s).ProcedureStatsTotalsTests+ProcedureStatsTotalsWriterLiveTests: 16 passed, 0 failed. Live facts: totals equal a GROUP BY over the rows for a 2-database batch and for a restart collection (every interval 0); a second batch at the same collection_time recomputes; a re-run of the upsert changes nothing; NULL-interval rows stay NULL and a NULL database_name is one group; a refused totals write rolls back the COPY; the read-back plans an index scan; the retention statement keeps totals at or after the oldest raw row and deletes older ones. Clock: 95 h window routes Raw at 0, 1, 7 and 250 ms (and Hourly with the old late clock, for contrast).*Census*,*Ratchet*,*Pins,*RungTests,*ViewerSchemaVersionGate*,*StoreSelfMetrics*,*DarlingRetentionTests,*Hygiene*,*CommandTimeout*,*MigrationLadder*,*QueryStatsHourLedger*): 1,464 tests, 17 failed on the first run. All 17 were this change's version bump (probe ordinals in five rung tests, the V170-rung ladder, one regex pin for the transaction term); fixed. Re-run of the fixed classes plusCaggGroupIndexDrop*,ProcedureStatsTotals*,DarlingMcpTrendToolsTests: 83 passed, 0 failed after one more fix (PlanRegressionRowcountRungTests, 72 passed, 0 failed on the second re-run withViewerSchemaVersionGate*,MigrationDataMovingRungCensusPins,MigrationLadderPins). I did not re-run the whole 1,464-test sweep after the fixes.A95HourWindowWithNoAsOf_RoutesRawEveryTimeasserts the old late clock gives Hourly.origin/dev(one commit, Role provisioning stops before it sets a password when it cannot change the roles; store connection strings are reported without their values #5697) into the branch; no conflicts.Lane B: the raw trend reads the totals
The statement.
DurationTrendRouting.ProcedureCollectionsCte(the per-collection CTE underBuildBucketedRawTrendSql("procedure_stats", ...), so the MCPget_procedure_duration_trend, the Viewer chart and the web chart all get it with no caller change) now stitchesstoredat the per-server floor:totals_floor=SELECT COALESCE(MIN(collection_time), 'infinity'::timestamp) FROM collect.procedure_stats_totals WHERE server_id = $1. A server with no totals has the floorinfinity, so every collection reads the rows, as before.stored=procedure_statsgrouped by collection_time withcollection_time < (SELECT floor_time FROM totals_floor),UNION ALLthe totals table grouped by collection_time (every totals row is at or after the floor by definition). Each arm keeps the$2 - 1 hourto$3bounds. No collection is read from both.SUM(total_elapsed_time) / 1000.0,SUM(total_execution_count),MAX(max_sample_interval_seconds); filteredCOALESCE(SUM(.) FILTER (WHERE match), 0)for the two sums andCOALESCE(SUM(row_count) FILTER (WHERE match), 0)::bigintformatched_rows(the cast gives the bigintCOUNT(*) FILTERgives).matchis the unchanged$4::text[] IS NULL OR database_name = ANY($4), so a NULL database never matches on either source. NULL sums and NULL intervals stay NULL (SUM and MAX over NULLs), so the three-state interval contract (Measurement-layer campaign: the delta honesty contract (11 findings, one keystone) #3540/procedure_stats keeps only the top 150 procedures by lifetime elapsed time, and on busy primaries it misses about 16% of procedure CPU #5449) reads the same: a restart collection (every interval 0) stays unrated, a NULL interval stays NULL.runs,events,sequenced,points,gapped,rawand thecollection_logidle-run axis are byte-for-byte unchanged. The output columns ofstoredare unchanged, and the test compares every column's name and Postgres type between the old and new statement.Why the COALESCE sits inside the floor CTE. A scalar aggregate always returns one row, so
COALESCE(MIN(...), 'infinity')insidetotals_floormakes the floor never NULL and the rows arm carries a plaincollection_time < (SELECT floor_time FROM totals_floor). I tried the first draft (the COALESCE in the rows arm's WHERE) too; the plans for the windows below came out the same either way, so this is the simpler text, not a plan fix.Store below V176. The brief for Lane A said a store below the rung falls back to the rows. One static statement cannot do that (it names the table), and the seat asked for one statement. The Viewer's connect gate (
RequiredStoreSchemaVersion, the probe already carries theprocedure_stats_totalssentinel) blocks a store below the rung, and the service migrates before it serves a read, so the table exists wherever the statement runs. The remaining hole is the Viewer's fail-open probe (a probe that errors lets a skewed store through); the statement then fails with 42P01, which the executor already translates. Coordinator: say if you want a separate rows-only statement chosen byGetStoreSchemaVersionAsync; it would need a caller change in each of the three readers.Plan check (functional only; no performance claim). Throwaway scratch store, PostgreSQL 18.6, also with TimescaleDB 2.30.1 and
procedure_statsconverted to a 1-day-chunk hypertable. 72 h of 5-minute collections for server 1 (500 rows each, 4 databases, 432 K rows), totals for the last 48 h (floor = now minus 48 h), plus totals for 39 other servers so the floor lookup is not the only server in the index. Filtered statement, 60-minute buckets,EXPLAIN (ANALYZE, BUFFERS):idx_procedure_stats_timerange, 6 buffers; TimescaleDB: index range in each of the 2 day chunks the window touches, 0 rows, 7 buffers; no chunk is excluded at run time here, the Merge Append of per-chunk index scans carriescollection_time < InitPlanas an Index Cond)ux_procedure_stats_totals, rows=1idx_procedure_stats_time; TimescaleDB ChunkAppend: "Chunks excluded during runtime: 1")ux_procedure_stats_totalsix_procedure_stats_totals_timeWith ONE server in the totals table the planner looked up the floor through
ix_procedure_stats_totals_timewith a server filter; with 40 servers it choseux_procedure_stats_totals, which is the one that matters for a real store. Indexes: rows armidx_procedure_stats_time (server_id, collection_time)on both store kinds; totals armux_procedure_stats_totals(and the time index for a window with no server key match);collection_logunchanged (idx_collection_log_watermark). For a window after the floor the rows arm reads no row and no heap page; on TimescaleDB it still probes the index of each chunk the window touches (the table above), it is not excluded at run time there. I did not restructure further because those probes read 0 rows and 7 buffers in total.Tests.
ProcedureTrendTotalsStitchLiveTests.TheStitchedStatementReturnsTheBucketsTheRowsOnlyStatementReturns(live, own scratch store): server 7 has 24 five-minute collections; the first 12 are rows only (a store upgraded mid-stream), the rest go through the product'sWriteBatchAsync, so their totals are the real writer's. They include a restart collection before and after the floor (interval 0, deltas 0), an all-NULL-interval collection before and after, a collection with a NULL database_name (one totals group), a collection whose deltas are all NULL, a collection that stored one database only, and two collections that stored nothing (idle runs incollection_log, one each side of the floor), plus a FAILED run. Server 8 holds the same rows and no totals at all; server 99 holds nothing. The oracle is the statement as it ran before (the oldstoredblock kept in the test and spliced into the new text), run on the same store. 3 servers x 4 windows (after the floor, straddling it, before it, everything) x 5 filters (unfiltered, filtered with a NULL list, database A, B and C, a database with no rows) x bucket widths 1 and 60 minutes = 120 comparisons, 64 of them non-empty: every column name and Postgres type, and every row's every value, equal. A setup assert checks the floor is the first writer collection, nothing is totalled below it, the idle collection has no totals row and the NULL database is one group. Revert-proof: changing the rows arm tocollection_time <= floor(double-counts the floor collection) fails it on the straddling windows.ProcedureTrendTotalsStitchLiveTests.TheStatementReadsTheTotalsAtOrAfterTheFloorAndTheRowsBelowIt: text pin for the totals arm, the floor CTE, the rows arm's< floor, the::bigintmatched_rows sum, and that the oracle differs from the new text.DarlingMcpTrendToolsSurfaceAndSqlTests.ProcedureDurationTrendSql_PrefersTheStoredInterval_NeverFabricatesZero_AndMirrorsTheViewerthecollection_time >= $2 - INTERVAL '3600 seconds'count 2 to 3 and thecollection_time <= $3count 2 to 3 (one more arm each), the viewer-vs-MCP CTE comparison now also treats thetotal_elapsed_time/total_execution_countlines as the filtered-sum lines, and its FILTER count instored3 to 6; inDurationTrendDatabaseFilterLiveTests.TheFilteredStatements_CarryTheListPredicate_OnEveryArmthe procedure statement's FILTER count 3 to 6 (three per arm). The other pins compare the Viewer/MCP constants to the builder's output, so they moved with it.DarlingMcpTrendTools*,DurationTrendDatabaseFilter*,ProcedureTrend*,ProcedureStats*,McpZeroIsAMeasurement,DeltaFamilyIntervalCompletion*, the Viewer trend bucketing/routing classes,DarlingTrendReaderStitch,WebReadReach*,McpToolGuideHeadsSqlTail*, ...): 674 tests, the one failure of the first run was theDurationTrendDatabaseFilterLiveTestspin above, fixed. Census / ratchet / hygiene / command-timeout / collector-coverage / schema-gate / pin classes: 1,243 tests, 0 failed, 2 skipped. Build0 Warning(s). The wholeDarling.Testssuite is not run on this laptop; CI decides.For the coordinator. (1) The "store below 176" paragraph above. (2) The test takes about 35 s because it loads rows one at a time; I left it so the data stays readable. (3) My PostgreSQL rig (port 55731, Lane A's data directory under the session scratchpad) is stopped. (4) Nothing in Lane A's write path, migration or retention was changed.
Review round 1
Four findings from the first review, all fixed in this PR.
procedure_statsthree times per DELETE.ProcedureStatsTotals.PrunePredicateis nowcollection_time < COALESCE($2::timestamp, $1).DarlingRetentionmeasures the raw floor once before the DELETE (ProcedureStatsTotals.MeasureRawFloorAsync): on TimescaleDB the earliestrange_startof procedure_stats' chunks fromtimescaledb_information.chunks(the The dimension GC floor probe times out against compressed history: v39 indexes cannot serve compressed chunks #1815 way, immune to compression), on plain PostgreSQL (or a hypertable with no chunks) oneSELECT min(collection_time). It binds the floor as$2through a new optionalsecondParameterofPurgeOneAsync. A chunk floor is never later than the true minimum, so it can only keep more totals. An empty procedure_stats gives a NULL floor and the cutoff alone decides, as before. A floor that cannot be measured skips this table's purge for the cycle (counted as failed, warned), because the guard cannot be evaluated.UpsertSqlnow takes$3(the batch's non-NULL database names, NULL array = whole collection) and$4(whether the batch holds the NULL database):AND ($3::text[] IS NULL OR database_name = ANY($3::text[]) OR ($4::boolean AND database_name IS NULL)).UpsertBatchAsyncgets adatabaseNamesargument; the runner's writer call passes the distinctDatabaseNames of the batch'sProcedureStatsCollector.Rows (null for any other row type, which reads the whole collection). Totals are per database and a batch holds whole databases, and the read-back still counts rows of the same database from earlier batches, so the result stays exact.ProcedureStatsTotals.GapFillSqlruns first in the writer, in the same transaction: it totals every collection of the server that hasprocedure_statsrows strictly after the server's newest totals row before this batch and strictly before this batch. A server with no totals row needs nothing (the raw arm reads it). EXPLAIN (ANALYZE, BUFFERS) on the rig for the normal, empty case: anIndex Only Scan Backward using ux_procedure_stats_totalsfor the newest earlier totals row (2 buffers, 1 search), thenIndex Scan using idx_procedure_stats_time on procedure_statswithIndex Cond: server_id = ... AND collection_time < $2 AND collection_time > (InitPlan), 0 rows (3 buffers, 1 search); total execution 0.135 ms, no Seq Scan.OnTimescaleDb_WithACompressedOldestChunk_...builds the store's hypertables, compresses the oldestprocedure_statschunk, and checks the floor equals the chunk catalog's earliestrange_start(strictly earlier than the oldest row's own time, so it did not come frommin()), that the sweep's DELETE with a far-future cutoff removes nothing while that chunk is held, that after the chunk is dropped only the totals older than the new floor go, and that with no raw chunk left the cutoff alone decides. The existing plain-PostgreSQL retention test now binds the floor the same way and adds the exact-min floor and the empty-table case.Tests added:
PerDatabaseBatchesAtOneCollectionTime_TotalOnlyTheirOwnDatabases_AndStayExact(three per-database batches at one collection_time, a sentinel in DbA's totals that DbC's batch must not touch, a later DbA batch recomputing from both of its batches, the NULL database through$4, and the whole-collection null-names path),ACollectionAnOlderBinaryWroteAboveTheFloor_IsTotalledByTheNextBatch_AndTheTrendEqualsTheOldStatement(totals at t1, rows without totals at t2, batch at t3; the stitched trend equals the old-SQL oracle for unfiltered and filtered at widths 1 and 60, and it differs from the oracle before the t3 batch, so the test is not vacuous; plus the plan assertion),AServerWithNoTotalsYet_IsNotBackfilledByTheFirstBatch_..., and two text pins inProcedureStatsTotalsTests(gap fill shape, retention predicate has no procedure_stats scan and the floor is measured before the DELETE). I did not run a revert of each fix to watch its test fail; the sentinel and the not-vacuous comparison are the guards.Verified on a throwaway PostgreSQL 18 with TimescaleDB (port 5872, stopped): the Writer, Totals, Stitch and DarlingRetention classes (72 tests, 0 failed) and every Census and Ratchet class plus the command-timeout, doc-comment, live-hygiene, store-upgrade, migration and duration-trend classes (923 tests, 0 failed, 13 skipped). Not run here: the rest of the suite, which CI runs.
Review round 1 follow-up (seat)
Claude posting for Erik Darling.
Defect. The gap fill (
ProcedureStatsTotals.GapFillSql) ran first in the procedure_stats COPY transaction with no savepoint, so its failure failed the batch. After a rollback to a pre-V176 binary that ran for days the gap can hold millions of rows. If the statement timed out or failed, the batch rolled back and no totals row was written at that batch's time. The next batch saw the same anchor and the same gap and failed again, so procedure_stats collection stopped for that server for good.Fix (
ProcedureStatsTotalsWriter). The gap fill now runs behind a savepoint (pst_gap, the #3953 shape) and under a server-sidestatement_timeout. On any non-cancellation fault the writer runsROLLBACK TO SAVEPOINT, logs a warning naming the server and the gap range (after <newest earlier totals row> and before <batch time>), and goes on to the batch's own upsert. The batch commits, its totals row becomes the new anchor and the gap is attempted exactly once; those collections stay out of the trend, which is the behavior before this PR, not a regression. The batch's own upsert is unchanged: still no savepoint, still fatal to the batch.Timeout choice: the server-side bound, not the #3953 pattern alone. The #3953 pattern (
SET LOCAL lock_timeout, then a savepoint) only bounds lock waits; its statements rely on Npgsql'sCommandTimeout, which on expiry sends a cancel request, and a failed cancel breaks the connection (the savepoint rollback and the upsert would then fail too). So the gap runs underset_config('statement_timeout', '<half of CommandTimeout, min 1 s>ms', true)set inside the savepoint, while the client's own deadline stays at the full command timeout, so the server cancels first (57014) and the connection stays healthy. On success the previous value (read in the same round trip that reads the gap's start) is put back, because aSET LOCALoutlives a released savepoint and would otherwise bound the batch's own upsert; on failure the rollback to the savepoint undoes it.Read-back limit type check. The call site was
(object)rows is List<ProcedureStatsCollector.Row>. Traced: every procedure_stats write, the server path, the Azure per-database fan-out and an import, goes throughCopyBatchOnceAsync<TRow>(... List<TRow> rows ...), and the catalog's only definition for the table is aCollectorDefinitionBase<Row>, so TRow isRowand the check matched on every shipped path. It was still fragile (any other collection shape, or an import definition with another row type, silently read the whole collection). The check is nowProcedureStatsTotalsWriter.DatabaseNamesOf(rows), which accepts anyIEnumerable<ProcedureStatsCollector.Row>(list, array, read-only collection) and returns null only for other row types.Tests.
ProcedureStatsTotalsWriterLiveTests(PostgreSQL, scratch database):AFailedGapFill_DoesNotFailTheBatch_AndTheNextBatchDoesNotRetryIt(a trigger refusing the gap database's totals row stands in for the fault; through the product's ownWriteBatchAsyncthe batch's rows and totals commit, the gap stays untotalled, and after the fault clears the next batch still does not retry it);AGapFillThatTimesOut_IsCancelledByTheServer_LogsTheRange_AndTheBatchStillCommits(a trigger sleeping 30 s under a 300 ms bound; the transaction'sstatement_timeoutis back to its original value after the rollback, the warning carries the server name and both ends of the range, the commit lands);TheGapFill_TotalsARealGap_LogsNothing_AndRestoresTheStatementTimeout(the normal path: a real gap is totalled, nothing is logged, the timeout is restored, and the next empty-gap batch is normal);TheReadBackLimit_ReachesTheWriter_OnTheRunnersOwnPath(a second batch holding only DbA does not recreate the deleted DbB totals row).ProcedureStatsTotalsTests:TheReadBackLimit_MatchesEveryRowCollectionShape_AndEveryProcedureStatsPathCarriesRows(List, array, IEnumerable, read-only collection, other types, plus the call-site trace and a catalog census of the table's definitions) andTheGapFill_RunsBehindASavepointAndAServerSideTimeout_AndNeverFailsTheBatch(statement order pin).ProcedureStatsTotalsTests16/16,ProcedureStatsTotalsWriterLiveTests10/10 (incl. the 4 new),ProcedureTrendTotalsStitchLiveTests4/4, plus the census/ratchet/command-timeout classes (DocCommentHygiene, Storage/Startup/CollectionSweep CommandTimeout, LivePostgresCollectionHygiene, LiveCleanupConversionRatchet, ScratchDatabaseDisposal, StoreApplicationName, LiveClock, TimingTest, SlowClass, PgClusterObject, QueryStatsWriterCensusPins, LivePlanShapeIsolation, StoreSessionTimeZonePin, UnpooledDropConnection): 271 tests, 0 failures after removing a Stopwatch my first draft used (TimingTestCensus). The full Darling.Tests suite was not run on this laptop; CI runs the rest.ProcedureStatsTotalsWriter.cs, the writer call (and its comment) inCopyBatchOnceAsync, and the two test files.ProcedureStatsTotals.csunchanged.Review round 2 fixes
Claude posting for Erik Darling. Round 2 findings (
helper-7-5706-r2.md) and the CI failure, fixed on commit 131858d.max(totals) <= batch timein both the probe and the gap statement, so batch 2 at the samecollection_timesees batch 1's committed row, its range is empty and the gap statement never runs.s.collection_time < $2is kept. A batch that rolled back leaves no anchor and still retries. The "attempted exactly once" class doc and the "not retried" warning now say what is true (once per committed batch, never once per batch of a cycle). Live testTwoBatchesAtOneCollectionTime_TryAFailingGapOnce_...: a trigger bumps a sequence per gap attempt (rolled-back batch = 1, committed batch 1 = 2, batch 2 and the next cycle stay 2) and one warning is logged. With<put back, the test fails (Expected 2, Actual 3).ProcedureStatsTotals.GapProbeSqlreads the currentstatement_timeout, the anchor and anEXISTSgap probe in one statement before the savepoint. With no anchor or no gap the method returns there: no savepoint, noset_config, no gap statement. Pinned live throughpg_stat_statements(2 probes for 2 batches, 0pst_gap, 0set_config, 0 gap statements) and by a source pin (oneExecuteReaderAsync, probe then early return then savepoint).$3inGapFillSql, not a subquery. The existing TimescaleDB compressed-chunk live test now EXPLAINs the gap statement with anchor day 9 and batch day 11: only the chunk overlapping (anchor, batch) appears, the other two chunks (including the compressed oldest) are absent, and there is noDecompressChunk.PlainRawFloorSqltakes the minimum over the servers that have totals rows (a loose index scan of the totals key) of each server's ownORDER BY collection_time LIMIT 1throughidx_procedure_stats_time(a LATERAL). Doc corrected. EXPLAIN pin (ThePlainFloor_IsAnIndexProbePerServerWithTotals_..., four servers, one without totals):Index Only Scan using idx_procedure_stats_time on procedure_stats p,Index Cond: (server_id = servers.server_id),loops=3, no seq scan; the server without totals does not move the floor.PurgeOneAsynctakes asecondParameterFactorythat runs on the purge's own connection after theSkipTableOnBudgetgate;PurgeAsyncno longer opens a connection for the floor. Source pin: gate, thenOpenConnectionAsync, then the factory call.DarlingRetention.PurgeAsync: plain store (the two expired totals go, the recent one stays), TimescaleDB store (raw chunks held, so all three totals stay; after the gated drop of the oldest chunk the next sweep purges only the totals below the new floor), and the floor-failure branch (procedure_statsrenamed away: the totals are untouched, a warning namescollect.procedure_stats_totals, and the next sweep with the table back catches up). The text pin ofsecondParameter: new NpgsqlParameteris replaced by pins of the factory and the gate order.QueryStoreComposeStampTests.TheProbe_HasThisRungsSentinelAndMapsItsArmToV173, shard 1): V176's sentinel is probe ordinal 151. The pin now reads V176 as the newest (ProbeOrdinal + 3present,+ 4absent,arity - 1 == ProbeOrdinal + 3), and the "behind" and "at this rung" fixtures clear the extra ordinal. I grepped every otherProbeOrdinal/arity - 1/GetBoolean(DoesNotContain pin in Darling.Tests: the other rung tests (ServiceVersion, PlanRegressionRowcount, Aws, LegacyPinCandidate, PlanRegressionDaily) assert ordinals that remain absent or present at V176, and the run below passes them.RunnableQueueSettingsRungTestsdoes not exist on this branch (PR Alerts: a Runnable Queue alert on runnable tasks per scheduler, for Lite and Darling (#5641) #5709).LiveClockCensusTestsflagged the new live tests (they EXPLAIN and read the clock); they seed fromLiveClock.Now().Shards: at 131858d's parent,
gh pr checks 5706showed "Darling PG tests (0)", (2), (3), (4), (5) passed and only (1) failed (the pin above); "Darling PostgreSQL tests" is the aggregate of (1). No unrelated failure to report.Local run (rig on its own port, UTC,
shared_preload_libraries = timescaledb,pg_stat_statements): every*Census*,*Ratchet*,*QueryStoreComposeStamp*,*ProcedureStatsTotals*,*ProcedureTrend*,*Retention*,*SchemaProbe*,*Rung*,*ViewerSchemaVersion*,*DocCommentHygiene*, StartupCommandTimeout and StorageCommandTimeout classes: 1441 tests, 1 failure (the LiveClock census above, fixed); rerun of the touched classes plus the census: 179 tests, 0 failed, 0 skipped. Build: 0 warnings, 0 errors. The full CI suite is not run here.Behavior change for the changelog entry: none user-visible (the gap and retention paths only get cheaper and stop repeating work), so the proposed entry below stands.
Proposed changelog entry
Notes for the coordinator
Seat decision (pm-worker-helper-7)
No rows-only fallback for a store below V176. The service migrates before it reads, and the Viewer connect gate (the V176 sentinel in this PR) blocks an older store, the same as every other read of a newer table. A probe that errors and fails open makes this read fail with 42P01, as the other newer-table reads already would.