Repository navigation
DMV blocking snapshots no longer merge two separate waits of one pair (#5743) - #5766
Conversation
…re reads tempdb's live size (#5644 W4, W5)
…t, Deadlock trend, honest labels (#5644)
…5644-web-ui-audit-lane-d
…en SYSDATETIME and ms_ticks drift (#5644 W3)
…5644-web-ui-audit-lane-d
… zero-normal collectors (#5644 W8 W10 W13 W15)
…nt local (#5644 W11 W12 W20)
…t banner, job history and plan corrections repeats (#5644)
…ow of each DDL; readers drop stored copies (#5644 W6)
…5644-web-ui-audit-lane-b
…lizeIsoText together (#5644)
…king-wait SQL against seeded reports (#5644 W1, W3)
…the restart banner start times (#5644)
… lexical check always, live SET PARSEONLY when DARLING_TEST_SQL is set (#5644 W5)
…keep reused plan-correction names per query (#5644 W1, W21)
…stored rows of that tick by EventSequence (#5644 W6)
…ng filter reaches the linked watermark test
… hours and worst_count (#5644) W1 made the displayed blocking counts WAITS, but the health band's 5/20 per-hour tiers were measured in blocked-process reports, so a long wait stopped banding by count. The fleet card and the viewer summary keep waits for display and hand the band the report count. /api/fleet refuses hours outside 1..168 and a negative worst_count with the invalid envelope instead of clamping.
…counts; displayed counts stay waits (#5644)
…filter interpolated
…#5743) A new wait of a pair cannot start before the previous wait was last seen alive: a row also starts a new wait when its derived start is more than WaitStartJitterMs (150) after the latest event time of the pair's preceding rows. One rule in Collapse, and in WaitsCteSql for PostgreSQL and DuckDB. Blocked-process report counts are unchanged.
… 500 ms wait floor bounds a false split (#5743)
The changelog justification does not hold up against the treeThe body closes with:
There is no such entry in this checkout.
This checkout contains dev ( That matters more than a bookkeeping slip, because this PR does change a number operators read. For any server answered by the DMV fallback — AWS RDS, and anywhere the blocked_process_report XE captured nothing — a pair that re-blocks inside the 2 s tolerance now counts as two waits instead of one, on the Lite overview card ( Two ways to settle it, either is fine:
Nothing else in the body needed correcting. The design argument ("a new wait of a pair cannot start before the previous wait was last seen alive"), the two implementations, the 150 ms derivation and every one of cases 21-27 check out against the code — details in the review. |
There was a problem hiding this comment.
Verdict: CHANGES REQUESTED
I derived all seven DMV cases by hand before reading the body. C# (BlockingWaits.cs:110-133) and SQL (:188-200) agree with each other and with DmvExpectedWaits. The new arm is monotone — it only ADDS splits — so nothing that counted before can now undercount. The sole request is the changelog claim (top-level note); the three inline comments are non-blocking.
Claims
- VERIFIED — the issue's two rows now count as two —
:117-118: 1700 <= 2000 passes the old arm, 200 > 150 fires the new one (case 21,BlockingWaitCountTests.cs:401) - VERIFIED — "more than
WaitStartJitterMsafter the LATESTevent_timeof all preceding rows (same start order)" —:117-118with the running max at:109,129-132; SQL twin:196over the sameORDER BYas theLAGat:192-193 - VERIFIED — "No output column was added; the order and tie-breaks are the same as C#" —
:196adds only an OR arm inside the existingCASE;:201-215unchanged;starts_wait/wait_noappear in no other file - VERIFIED — "A NULL max puts no constraint" — a partition's first row is already caught by
WHEN LAG(...) IS NULL(:192) andTRUE OR NULLisTRUE - VERIFIED —
event_timeis the collector's start-of-run stamp —DmvBlockingSnapshotCollector.cs:273;RemoteCollectorService.DefinitionRunner.cs:107andDarlingCollectorRunner.cs:2149stamp ahead of the watermark read and the query - VERIFIED — both stores keep microseconds —
PgSchemaGenerator.cs:47,DuckDbSchemaGenerator.cs:61,CollectionTimeClock.cs:69-75 - VERIFIED — the 500 ms / 1 s / 2 s / 5 s floors —
DmvBlockingSnapshotCollector.cs:195-202; and 200 would indeed re-merge case 21, the comparison being strict - VERIFIED — "never changes a report count" for blocked-process reports — holds for any threshold (
start(i) - event(j) = jitter(i) - jitter(j) - wait(j),wait(j)positive), pinned both ways byBlockedProcessReports_KeepTheirWaitCounts_AndReportCountsand...KeepTheirWaitCounts - VERIFIED — cases 23-27 — case 27's third row starts 200 ms past the previous row's event, so a
LAG-only form splits it (:407); 9850/9849 sit exactly at 150 and 151 ms, every operand an integral ms well under 2^53, so the arithmetic is exact in C# and both stores - VERIFIED — "Lite's
BLOCKING_EVENTSfact reads reports only" (BlockingWaitDuckDbTests.cs:396); test counts 19 (was 16) and 14 match the[Fact]members; the diff is exactly the three files claimed - UNVERIFIED — every build/test and red-plant result — no .NET SDK here, and the PostgreSQL arms are gated on
DARLING_TEST_PG - UNVERIFIED — that real lead time varies by under 150 ms — the body says so itself; needs a timed run against a live instance
- REFUTED — "ENTRY: none ... #5705's entry covers it" — no such entry.
[Unreleased](CHANGELOG.md:22-33) holds #5663, #5668, #5665, #5659, #5682 and nothing on blocking;grep "5705\|5644" CHANGELOG.md docs/changelog/*.mdis empty, and this checkout already contains dev (3f3b9c1d, the commit the body names as #5705's merge). Two ways to settle it in the top-level note
Riskiest lines
PerformanceMonitor.Common/BlockingWaits.cs:118— the in-memory arm; a sign error changes every blocking count silently — pinned byDmvSnapshots_AWaitCannotStartBeforeThePreviousWasLastSeen(CI) andBlockedProcessReports_KeepTheirWaitCounts_AndReportCountsPerformanceMonitor.Common/BlockingWaits.cs:196— the SQL twin; one string feeds 13 read sites in both SKUs (Lite's card/badge/daily summary,DuckDbFactCollector.Waits.cs:256,PgFactCollector.Waits.cs:277,DailySummarySql.cs:242,DarlingFleetReader.cs:372,DarlingHealthReader.cs:93, threeViewerDataServicereads), failing at read time not build time — pinned byDuckDbSql_AgreesWithTheCSharpRule_OnDmvSnapshotRows(CI) and its PostgreSQL twin (live only). No caller is unpinned: each already projectsevent_time, which:185requiredPerformanceMonitor.Common/BlockingWaits.cs:68— the 150 ms constant; its boundary is pinned exactly by cases 24/25, its fitness against real lead times is UNPINNED
Traps near this diff
- "Two copies of one definition pinned EQUAL to each other fail only after BOTH have drifted (#3684). Alias, do not copy." — does not apply — C#/SQL are two forms of one rule by necessity (
BlockingWaits.cs:42-44) and are not pinned only to each other:DmvExpectedWaits(BlockingWaitCountTests.cs:411-414, mirroredBlockingWaitDuckDbTests.cs:341-344) is an absolute count, so a both-sides drift still fails - "Lite and Darling ship in parity ... a fix to one SKU's reader, tool, alert or description without the counterpart's is a finding" — does not apply — the fix is wholly in shared
PerformanceMonitor.Common/BlockingWaits.cs:117-132,196, both test projects covered in the same diff - "A pin that encodes the lie ... Ask what a pin would fail ON." — does not apply — case 27 (
:407) fails against a previous-row-only form and cases 24/25 straddle the strict comparison by 1 ms - "Integer division in a rate column ... suspect until a
1.0 *or a CAST is found." — does not apply — the new comparison isDOUBLEthroughout (:177-180) against an integer literal - "A test that reads the clock twice measures the CI scheduler. One anchor owns both ends of an interval." — does not apply — the Lite tests derive every stamp from
_windowEndviaAgo(BlockingWaitDuckDbTests.cs:29,116); the Darling cases are offsets from staticT0 - "An alert evaluated every ~30 s against an observation that changes once per COLLECTION re-fires on every cooldown expiry ...
AlertPersistenceGateat K consecutive collections." — does not apply — the diff changes what the count IS, not its gate;AlertContextBuilders.cs:491is untouched and consecutive-cycle rows already split on the 2 s tolerance
Divergence (blind read vs PR body)
One: the refuted claim. ENTRY: none rests on a #5705 changelog entry that is not in the tree, so this operator-visible count change has no changelog line anywhere. Everything else matched, including the parts most liable to overstatement — the running max really spans all preceding rows, case 27 really would fail a previous-row-only form, and the no-regression claim really is pinned on both stores.
Two prose-vs-code gaps, non-blocking, posted inline: the WaitStartJitterMs false-split sentence has its lead comparison inverted relative to the start order the rule sorts by (its 650 ms conclusion still holds), and the retained WaitStartToleranceMs doc still cites "a store that keeps only seconds" two lines above the new paragraph saying none is read here.
Reviewer checklist
- Run both extended classes with
DARLING_TEST_PGset — without it the three PostgreSQL arms skip, so CI never exercises the new window on PostgreSQL. I could not build: no .NET SDK here - Confirm no other suite's count flipped: the new arm splits same-pair rows spaced between
wait_time_ms + 150and 2000 ms, a band the old rule merged. The fixtures I read look safe (DailySummaryBlockingWaitsLiveTests.PlantAsync,BlockingBandReportUnitLiveTests.PlantAsyncand Lite'sSeedWaitAsyncall writeevent_time = start + wait; theAzureMaster*ScopeTestsspace rows a minute apart or per spid) — but that was reading, not running - Take one live lead-time reading, cold connection and pooled: the one input to the 150 ms choice the tree cannot supply, and a cold lead above ~650 ms would split a continuing minimum-length wait
- Decide the changelog question
|
Claude posting for Erik Darling. On the refuted #5766 corrects how that same unreleased change splits DMV snapshot rows into waits, so it ships inside that entry and needs no line of its own: no released version ever counted DMV waits the old way. The body's ENTRY line now says "buffered" so the next reader does not look in The three inline notes are being fixed on this branch (one epoch helper per dialect, the tolerance doc without the whole-seconds clause, and the jitter doc's lead comparison); each thread gets its own reply with the commit. |
…ance docs say what the code does (#5743)
|
Follow-up review of This commit does exactly what the previous review's three inline notes asked for, and does them correctly:
No behavior changed: the generated SQL string is byte-identical before and after (confirmed by hand, not just by inspection of the ternaries), |
There was a problem hiding this comment.
Verdict: LGTM
Claims
- VERIFIED — title: "one epoch helper per dialect" —
EpochMsSql(dialect, column)added atBlockingWaits.cs:153-156, called twice at:182-183in place of the oldstring.Replace("s.event_time", "m.event_time")derivation; output is byte-identical for bothSqlDialectvalues. - VERIFIED — title: "the jitter and tolerance docs say what the code does" — the
WaitStartJitterMsdoc's lead-comparison sentence (:62-65) was rewritten from a directional ("next row's lead longer than first row's") to a symmetric one ("the row with the longer lead"); re-deriving the split condition from the CTE's actual comparison (current.Start - latestEpochMs > WaitStartJitterMs, expanded viaderived_start = true_start - lead) giveslead_prev − lead_j > wait_prev + jitter, i.e. the row with the longer lead is the one whose wait bounds the gap — matches the new sentence exactly; the old one had it backwards. - VERIFIED — the
WaitStartToleranceMsdoc (:48-50) no longer claims "the whole-second rounding of a store that keeps only seconds", consistent with the adjacentWaitStartJitterMsdoc's statement that PostgreSQL and DuckDB both keep microseconds.
Riskiest lines
PerformanceMonitor.Common/BlockingWaits.cs:153-156—EpochMsSql: a dialect-SQL typo here would silently change the epoch math for every caller — pinned byDuckDbSql_AgreesWithTheCSharpRule_OnDmvSnapshotRows(Lite.Tests/BlockingWaitDuckDbTests.cs:347) andPostgresSql_AgreesWithTheCSharpRule_OnDmvSnapshotRows(Darling/Darling.Tests/BlockingWaitCountTests.cs:428, live-only)PerformanceMonitor.Common/BlockingWaits.cs:182-183— the two call sites now derive from the shared helper instead of a text-substituted copy; same tests as above confirm the generated SQL still agrees with the C# rule after the refactorPerformanceMonitor.Common/BlockingWaits.cs:62-65— the rewritten jitter-doc sentence; doc only, not pinned by any test, but independently re-derived above and confirmed to match the code at:199— UNPINNED (as prose, by nature)
Traps near this diff
- "Two copies of one definition pinned EQUAL to each other fail only after BOTH have drifted (#3684). Alias, do not copy." — does not apply as a defect; this commit is the remedy for the shape (replacing a text-substitution copy with one shared helper function) —
BlockingWaits.cs:153-156,182-183
Divergence (blind read vs PR body)
None — the title's two claims ("one epoch helper per dialect", "the jitter and tolerance docs say what the code does") match the diff exactly, and both match the three non-blocking items the prior full review (head=fd2c23d65...) raised inline.
Reviewer checklist
- None beyond the prior full review's checklist (live PostgreSQL run, a cold-connection lead-time reading) — this commit is doc/refactor only and changes no runtime behavior
Claude posting for Erik Darling.
Closes #5743.
#5705 merged to dev as 3f3b9c1. The seat merged dev into this branch (fd2c23d, built with
git merge-tree --merge-base f1f1f59b4because #5705 was squashed), so the diff is now the #5743 change only:BlockingWaits.csand two test files (110509f, plus the seat's doc fix 5fc9549).Summary
Blocking counts group the rows of one (blocked, blocker) pair into waits by derived start (
event_time - wait_time_ms). That is safe for blocked-process reports (a reported wait already lasted >= 5 s) but not for DMV snapshot rows, which catch a wait of any length. Wait A seen at T with wait 1,500 ms and a new wait B that starts 200 ms later and is seen at T + 10 s with wait 9,800 ms have derived starts 1.7 s apart, so they counted as one wait.Design
One rule for every source, no source-specific branch. A blocked session waits on one thing at a time, so a new wait of a pair cannot start before the previous wait was last seen alive, and a row's
event_timeis a moment its wait was observed alive. A row now starts a new wait when EITHER its derived start is more thanWaitStartToleranceMs(2000) after the previous row's start (unchanged) OR its derived start is more than the newWaitStartJitterMsafter the LATESTevent_timeof all preceding rows of the same pair (same start order).Collapse<T>: a running max ofTimeover all preceding rows of the pair, not just the current group.WaitsCteSql(PostgreSQL and DuckDB): the OR in{name}_gapped,MAX(<epoch ms of m.event_time>) OVER (PARTITION BY ... ORDER BY m.wait_start_ms NULLS LAST, m.event_time NULLS LAST ROWS BETWEEN UNBOUNDED PRECEDING AND 1 PRECEDING). A NULL max (no preceding row) puts no constraint. No output column was added; the order and tie-breaks are the same as C#.Why
WaitStartJitterMs= 150 msevent_timefrom the collector, not from the query.DmvBlockingSnapshotCollector.WritePayloadwritescontext.CollectionTime, and both runners stamp that at the start of the run (CollectionTimeClock.NextStrictlyAfter(..., DateTime.UtcNow)inRemoteCollectorService.DefinitionRunnerandDarlingCollectorRunner), before the store connection and the SQL Server connection open and before the query readswait_duration_ms. The derived start is therefore the true start minus that run's lead time (tens of ms on a pooled connection) and varies from run to run. The stamp is not in the same query, so the jitter is larger than a same-query stamp's.DmvBlockingSnapshotCollector~195), so that takes a run-to-run lead difference above 650 ms. (Seat, 5fc9549: the doc no longer claims an unmeasured "tens of milliseconds" lead time and cites this floor instead.)Tests
Extended
Darling/Darling.Tests/BlockingWaitCountTests.cs(PostgreSQL) andLite.Tests/BlockingWaitDuckDbTests.cs(DuckDB). Both run the C# rule and the SQL over the same rows and compare rows and per-pair wait counts.dmv_blocking_snapshotsrows).wait_reports1, 2 and 11 unchanged); on DuckDB the overview card, the analysis fact and C# agree on 3.Runs (rig: throwaway PostgreSQL from
pg-runtime.zip, UTC,pg_stat_statementspreloaded; stopped and deleted):BlockingWaitCountTests19/19 (16 before).BlockingWaitDuckDbTests14/14.*Blocking*,*DailySummary*,*FleetReadsAreBounded*,*Census*,*Ratchet*: 1019 passed, 0 failed.Stage=Guard: 1624 passed, 0 failed.*Blocking*,*DailySummary*,*Census*,*Ratchet*: 312 passed.Stage=Guard: 502 passed.*BlockingWait*+*DailySummary*101 passed, Lite*Blocking*+*DailySummary*245 passed.Red-plant (each restored afterwards):
|| (false && ...)):DmvSnapshots_AWaitCannotStartBeforeThePreviousWasLastSeenandPostgresSql_AgreesWithTheCSharpRule_OnDmvSnapshotRowsfail (2 of 19).OR FALSE AND ...):PostgresSql_AgreesWithTheCSharpRule_OnDmvSnapshotRowsfails (1 of 19); DuckDB:DuckDbSql_AgreesWithTheCSharpRule_OnDmvSnapshotRowsandDmvSnapshots_OfTwoShortWaits_LessThanTwoSecondsApart_AreTwoWaitsfail (2 of 14).For the coordinator to check
BLOCKING_EVENTSfact reads blocked-process reports only, so the DMV end-to-end test in Lite goes through the overview card, not the fact.SECTION: None
ENTRY: none (fixes blocking wait counting added by #5705 in this same unreleased cycle; #5705's buffered entry "Blocking counts one event per wait, not one per blocked-process report" covers it; the buffer is spliced into CHANGELOG.md at the release cut, so dev's [Unreleased] does not show it yet)