Skip to content

Credit a newly compiled plan's counter instead of discarding it (#2235) - #2290

Merged
erikdarlingdata merged 1 commit into
devfrom
fix/2235-credit-a-new-plans-counter
Aug 16, 2026
Merged

erikdarlingdata merged 1 commit into
devfrom
fix/2235-credit-a-new-plans-counter

Conversation

@erikdarlingdata

Copy link
Copy Markdown
Owner

Addresses the attribution half of #2235. The literal-fragmentation half already shipped (get_top_queries_by_cpu(group_by: 'host_object')).

The defect

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:

var deltaKey = $"{row.SqlHandle}:{row.StatementStartOffset}:{row.StatementEndOffset}:{row.PlanHandle}";

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:

Datadog sqlserver.queries.worker_time, one hash 43.1% / 43.9% / 42.5% of an 8-vCPU box, three windows
The same hash through these collectors, 168 h 18 executions, 2,824 ms
Instance-wide: top-25 procedures ~49M ms against roughly 498M core-ms available

The worse half: it was invisible

The calculator already had an honest path for cache churn. The counter-reset branch reports interval = 0 on purpose, so a reader can tell a fabricated zero from an idle one — the invariant #2234 rests on:

/* Counter reset (plan cache eviction/re-entry): the work between the two readings
   is unknowable, not zero. Report no interval either, so the pair stays honest [...] */

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_time has 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. PayloadColumns is unchanged and the age is not stored; the 51-column pin stays green.

Sent as an AGE, not a timestamp. A DMV creation_time is 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_stats at all, so no keying scheme can recover it. This fixes the recoverable half only.

Why plan_handle was 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: ClearServer now 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.Tests is net10.0-windows and cannot run on this machine, so I Compile-Include'd the new test file into a plain net10.0 console 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. EveryRowOfOnePassSeesTheSamePreviousPass pins 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

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;

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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).

@claude

claude Bot commented Aug 16, 2026

Copy link
Copy Markdown

Review

Reviewed the delta-calculator and query_stats changes for #2235. The core fix — passing compile_age_seconds so a recompiled plan's counter is credited instead of silently reporting 0 on first sighting — is sound: PreviousPass correctly tracks the (server, collector) pass boundary once per pass (stable across every row via the "advance only when collectionTime changes" guard), the credit path is properly gated by the existing gap policy, ClearServer drops the pass window with the baselines, and the default-interface-method forwarding keeps every other of the ~40 call sites and every existing ICollectorDeltaCalculator implementer untouched. Lite and Darling both derive from the shared CollectorDeltaCalculator without overriding the new method, and QueryStatsCollector.cs is a single file shared by both SKUs, so there's no parity drift here.

One correctness issue found, left as an inline comment on CollectorDeltaCalculator.cs: in the new credit branch, interval is set to the full inter-pass gap rather than the counter's actual accrual window (seriesAgeSeconds, which is already proven <= gap by the guarding condition). This doesn't affect the delta itself or the SUM-based CPU totals, but it dilutes worker_time_per_second (delta_worker_time / sample_interval_seconds) for exactly the newly-credited, plan-churning rows — the peak-rate metric that would otherwise make this class of spike visible stays under-reported, sometimes by orders of magnitude near the gap-policy boundary.

Everything else — the SQL (compile_age_seconds = DATEDIFF(SECOND, qs.creation_time, GETDATE()), correctly comparing two server-local-clock values rather than mixing in UTC), the ordinal bookkeeping in ReadAsync (age fixed at 43 in both capture modes, plan XML correctly pushed to 44), the unchanged 51-column PayloadColumns pin, and the test coverage in DeltaSeriesAgeTests.cs / QueryStatsCollectorDefinitionTests.cs — looks correct and thorough.

(Per repo convention, not flagging anything about missing-index DMV usage — out of scope here anyway.)

@erikdarlingdata
erikdarlingdata merged commit ec45bcf into dev Aug 16, 2026
6 checks passed
erikdarlingdata added a commit that referenced this pull request Aug 18, 2026
… 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>
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