Repository navigation
Credit a newly compiled plan's counter instead of discarding it (#2235) - #2290
Conversation
query_stats keys its deltas on the full dm_exec_query_stats row identity, which includes plan_handle -- and plan_handle changes on every recompile. So a statement whose dynamic SQL mints a new plan constantly presents a new key on nearly every sighting, and the first sighting of a key reports 0. Field measurement on a plan-churning readable secondary: a query Datadog measured at 43.1% / 43.9% / 42.5% of an 8-vCPU box across three windows read through these collectors as 18 executions and 2,824 ms over 168 hours. Instance-wide, the top-25 procedures accounted for ~49M ms against roughly 498M core-ms available. The worse half is that it was invisible. The counter-reset branch reports interval = 0 precisely so a reader can tell a fabricated zero from an idle one (#2234), but it needs the SAME key to reappear lower, and a recompile never does -- it arrives under a new key and takes the baseline path. Same class of harm as the 300-second gap policy #2233 replaced: it did not merely lose data, it invented quiet. The discriminator was already being collected: creation_time has been in this collector's SELECT all along. The row now also carries how long ago its plan was compiled, and when a series demonstrably began since the previous pass its whole counter accrued inside that window, so the delta is the full value rather than 0. No new collection, no schema change -- PayloadColumns is unchanged and the age is not stored. Sent as an AGE rather than creation_time itself because a DMV creation_time is in the monitored server's local time while collection times are UTC; comparing them client-side is a timezone bug on every server that is not UTC, so DATEDIFF is evaluated where both clocks are the same one. Stated rather than left to be discovered: a plan compiled AND evicted between two passes never appears in the DMV at all, so no keying scheme can recover it. plan_handle was deliberately NOT dropped from the key. Parameter-sensitive variants of one statement coexist in cache, so a statement-only key would collide across several live rows in a single pass and each delta would be computed against whichever row was processed last -- the multi-statement cross-contamination #2012 fixed, reintroduced from the other direction. The new entry point is default-implemented on the interface, so the other forty-odd delta call sites and every existing implementer are byte-identical. All eight of the row's counters take the rule together; crediting only some would make one row's metrics disagree about how much work it did. Verified by executing the new xunit facts in a plain net10.0 harness (Darling.Tests is net10.0-windows and cannot run on this machine): 11/11, including the gap-policy bound, the cold start, per-pass stability across every row of one sweep, ClearServer, per-server/per-collector isolation, and a pre-#2235 implementer still compiling. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
| if (gap > 0 && (maxGapSeconds <= 0 || gap <= maxGapSeconds) && seriesAgeSeconds.Value <= gap) | ||
| { | ||
| delta = currentValue; | ||
| interval = (int)gap; |
There was a problem hiding this comment.
interval is set to the full inter-pass gap, not the counter's actual accrual window — so worker_time_per_second stays diluted for exactly the churning-plan case this PR targets.
The credit here is correct (delta = currentValue), but a recompiled plan's counter only accrued over seriesAgeSeconds (compile time → now), which is guaranteed <= gap by the condition on line 202. Reporting interval = gap instead of interval = seriesAgeSeconds breaks the implicit "delta accrued over exactly interval seconds" contract that every rate consumer relies on (ViewerDataService.QueryStats.cs: worker_time_per_second = delta_worker_time / sample_interval_seconds / 1000.0).
Concretely: a plan compiles 5s before a collection pass that lands 300s after the previous one (a delayed sweep, or just ordinary jitter on top of a churn-prone workload). total_worker_time = 900 (all of it earned in those 5s). Delta is correctly credited as 900, but interval is reported as 300 instead of 5 — so worker_time_per_second computes to 900/300/1000 = 0.003 instead of the true 900/5/1000 = 0.18, a 60x under-report of the peak rate. At the boundary (age ≈ 0, gap ≈ maxGapSeconds = 3600), the dilution factor is unbounded.
This doesn't affect the SUM-based totals (avg_cpu_ms divides by delta_execution_count, not the interval) — the "43%-of-the-box discarded to 0" scenario from the PR description is genuinely fixed for those. But the peak/spike metric this same fix is meant to make visible stays quietly suppressed for every row that takes this new credit path.
Suggest interval = (int)seriesAgeSeconds.Value; here instead of interval = (int)gap; (age is already bounded by gap via the seriesAgeSeconds.Value <= gap check on line 202, so this can't report an interval longer than the real gap).
ReviewReviewed the delta-calculator and One correctness issue found, left as an inline comment on Everything else — the SQL ( (Per repo convention, not flagging anything about missing-index DMV usage — out of scope here anyway.) |
… ranking explains (#2320) (#2330) * cpu_attribution on the top-CPU rankings: what fraction of the box the ranking explains The last unshipped item from #2235's wishlist, split out as #2320. get_top_queries_by_cpu and get_top_procedures_by_cpu (both SKUs) now return the returned rows' summed CPU-seconds, the SQL process's measured CPU-seconds for the same window (avg cpu_utilization % x core count x window - both stores already collect every piece), and attributed_cpu_ratio. Twice earned per the issue: pre-#2290 the reads explained ~10% of the box and nothing said so, and the ratio catches impossible claims at a glance - the Datadog comparison died when its worker_time sum divided out to 137% of the box's available CPU-seconds. Above the process's own measured consumption the note says to distrust the numbers; below half it explains where unattributable CPU goes (evictions between snapshots, rows outside the top-N or filters, zero-cost rows, non-query CPU). The degrade rule is explicit and pinned: missing CPU series, missing core count, or coverage under 90% of the window omits the ratio rather than inventing one. One computation in PerformanceMonitor.Common (CpuAttribution), decision-table tested identically in both test projects and executed against the built assembly in a local harness (all cases pass); the denominator read windows on collection_time with the same bounds as the rankings, so numerator and denominator share collection gaps. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * Review catches: concurrent denominator reads, one shared window on Lite, honest Result doc The CPU aggregate and server-properties reads are independent, so both SKUs' tools now run them under Task.WhenAll instead of paying two sequential round-trips on every call. Lite's GetCpuWindowAggregateAsync takes the window explicitly and the tools capture one nowUtc backing both the aggregate read and the ratio math - Darling had that by construction, Lite sampled UtcNow three times for one disclosure. The Result record's doc no longer claims SqlCpuSecondsInWindow and AttributedCpuRatio are null together - the measured-zero case deliberately reports the zero, as the tests pin. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * Review catches: hoist Lite's nowUtc above the ranking read, and the %% doc artifacts The ranking read windows on its own internal UtcNow, so capturing nowUtc after it left the numerator and denominator skewed by the ranking query's duration. Hoisting the capture above the read shrinks the skew to call-entry overhead - zeroing it entirely would mean threading an instant into the shared ranking read's signature, which sub-microsecond drift against an hours window does not buy. The %% doc-comment artifacts (a template-escaping leftover) become %. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> --------- Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
Addresses the attribution half of #2235. The literal-fragmentation half already shipped (
get_top_queries_by_cpu(group_by: 'host_object')).The defect
query_statskeys its deltas on the fulldm_exec_query_statsrow identity — which includesplan_handle, andplan_handlechanges on every recompile:So a statement whose dynamic SQL mints a new plan constantly presents a new key on nearly every sighting, and a first sighting reports 0. Measured on a plan-churning readable secondary:
sqlserver.queries.worker_time, one hashThe worse half: it was invisible
The calculator already had an honest path for cache churn. The counter-reset branch reports
interval = 0on purpose, so a reader can tell a fabricated zero from an idle one — the invariant #2234 rests on:But it needs the same key to reappear with a lower value, and a recompile never does — it arrives under a new key and takes the baseline path instead. So the loss was indistinguishable from a query that simply had not run. Same class of harm as the 300-second gap policy #2233 replaced: it did not merely lose data, it invented quiet.
The fix, using a discriminator already being collected
creation_timehas been in this collector's SELECT all along (QueryStatsCollector.cs:91). The row now also carries how long ago its plan was compiled, and when a series demonstrably began since the previous pass, its whole counter accrued inside that window — so the delta is the full value rather than 0, reported with a real interval because it is knowable.No new collection and no schema change.
PayloadColumnsis unchanged and the age is not stored; the 51-column pin stays green.Sent as an AGE, not a timestamp. A DMV
creation_timeis in the monitored server's local time while collection times are UTC, so comparing them client-side is a timezone bug on every server that is not UTC.DATEDIFF(SECOND, qs.creation_time, GETDATE())is evaluated where both clocks are the same one.Bounded by the existing gap policy. A plan compiled during an hour-long outage is not an hour of work in the next minute, so the credit is refused past
DefaultMaxGapSeconds— the same guard the reset branch uses.Two things stated rather than left to be discovered
The ceiling. A plan compiled and evicted between two passes never appears in
dm_exec_query_statsat all, so no keying scheme can recover it. This fixes the recoverable half only.Why
plan_handlewas not simply dropped from the key, since that is the obvious first move and it is wrong: parameter-sensitive variants of one statement coexist in cache, so a statement-only key would collide across several live rows in a single pass and each delta would be computed against whichever row happened to be processed last. That is the multi-statement cross-contamination #2012 fixed, reintroduced from the other direction. Narrowing the key would require aggregating per statement before the delta, which changes what a row means — a defensible design, but a different and larger one.Blast radius
The new entry point is default-implemented on the interface, delegating to the existing method and ignoring the hint. So the other forty-odd delta call sites (perfmon, wait stats, file IO, …) and every existing implementer — including test doubles — are byte-identical until they opt in. All eight of the row's counters take the rule together, because crediting only some would make one row's metrics disagree about how much work it did.
Also fixed:
ClearServernow drops the pass window along with the baselines. Left behind, a re-added server's first pass would measure a series age against a look from before it was removed and credit a whole counter to an interval that never happened.Verification
Darling.Testsisnet10.0-windowsand cannot run on this machine, so I Compile-Include'd the new test file into a plainnet10.0console harness and executed the facts rather than assuming they transcribe: 11/11 pass, covering the fix itself, the gap-policy bound, a series older than the gap, the cold start, ordinary same-key subtraction, a reset on the same key still reporting the honest(0, 0),ClearServer, per-server and per-collector isolation, and a pre-#2235 implementer still compiling and behaving as before.One of those deserves calling out because it is the trap that would have made this look like it worked: every row of one pass must measure against the same previous pass. A collector calls in once per row, so if the first row rolled the pass window forward, every later row in that sweep would compare against its own pass, see a zero gap, and be credited nothing — the fix would then work for exactly one row per cycle.
EveryRowOfOnePassSeesTheSamePreviousPasspins it.The test fake also records the age now, overriding the default rather than inheriting it: the default forwards and drops the age, so a collector that stopped passing it would otherwise keep every existing pin green.
Not claimed here
That this closes the 43%-vs-18-executions gap. It removes the mechanism that provably discards a churning plan's work, and the direction and scale are right, but the confirming measurement needs a live window on the affected instance — which is what remains open on #2235.
🤖 Generated with Claude Code