What happens
FetchAndStorePlansAsync and FetchAndStoreQueryTextAsync stamp their probe sub-phase on a plain assignment at the end of the probe phase:
var verdicts = await QueryStoreFetchProbe.TouchAndProbePlansAsync(...); // <- can throw
...
context.PerItemPlanProbeMs = probeWatch.ElapsedMilliseconds; // <- jumped over
When that await throws, the assignment never runs. The method's own catch logs and returns normally, the call site stamps the parent PerItemPlanFetchMs, and the sub-split prints probe:0ms — so the other: residual, which is computed as parent - probe - target - write, silently absorbs the entire cost.
Why it matters
other: is documented as the method's own bookkeeping, and its doc comment says a large value there "is itself the finding (the cost would be in our own code, not in either database)". For a store round trip that timed out that is the exact inverse of the truth — and the split is currently being used to decide where to optimise the fetch path.
Observed on the use1 monitoring host, 2026-09-03:
01:33:01 [WARN] query_store plan fetch failed on 'multi-24' database [tenant_f] (1 consecutive)
01:33:25 [INFO] query_store [tenant_f] plan_fetch:43053ms = probe:0ms + target:0ms + write:0ms + other:43053ms (0 chunk(s), 0 ids)
Scale of the misattribution that day, across 311 split rows:
|
ms |
| total parent |
2,827,723 |
total other: |
44,319 |
| that single failed probe |
43,053 |
97% of the entire fleet's other: budget for the day was one failed store probe filed as our own bookkeeping. The correlation is exact: 1 plan fetch failed WARN, 1 row with probe:0 and parent > 1s, same number.
Why the existing pin did not catch it
StatementSplitTimingTests asserts probe + target + write + other == parent, and it held on every one of the 311 production rows (verified: checked=303 mismatched=0 over the parseable set). The arithmetic was never wrong — the residual did exactly its job. The defect is which phase the milliseconds were attributed to, which no value assertion on CollectorContext can express.
The target and write phases already stamp from finally blocks, with comments in #2811 explaining precisely this reasoning ("stamping only on success would report target:0ms for it — 'the target was free' is the exact misreading this change exists to end"). The probe was the one phase that did not get the treatment.
Fix
Hoist probeWatch out of the try alongside carryKey (the same hoist #2776 already does for the backoff key), track whether the success-path stamp ran, and stamp from the catch when it did not. Guarded by a flag rather than == 0 so a throw in the later target or write phases cannot overwrite an honest probe reading with the whole elapsed span.
Pinned by a new IL-reachability test: the probe setter must be invoked from inside an exception-handler region on both fetch paths. Proven red on origin/dev (calls=2 insideExceptionHandler=0, both setters) and green with the fix (calls=3 insideExceptionHandler=1).
What happens
FetchAndStorePlansAsyncandFetchAndStoreQueryTextAsyncstamp their probe sub-phase on a plain assignment at the end of the probe phase:When that
awaitthrows, the assignment never runs. The method's owncatchlogs and returns normally, the call site stamps the parentPerItemPlanFetchMs, and the sub-split printsprobe:0ms— so theother:residual, which is computed asparent - probe - target - write, silently absorbs the entire cost.Why it matters
other:is documented as the method's own bookkeeping, and its doc comment says a large value there "is itself the finding (the cost would be in our own code, not in either database)". For a store round trip that timed out that is the exact inverse of the truth — and the split is currently being used to decide where to optimise the fetch path.Observed on the use1 monitoring host, 2026-09-03:
Scale of the misattribution that day, across 311 split rows:
other:97% of the entire fleet's
other:budget for the day was one failed store probe filed as our own bookkeeping. The correlation is exact: 1plan fetch failedWARN, 1 row withprobe:0and parent > 1s, same number.Why the existing pin did not catch it
StatementSplitTimingTestsassertsprobe + target + write + other == parent, and it held on every one of the 311 production rows (verified:checked=303 mismatched=0over the parseable set). The arithmetic was never wrong — the residual did exactly its job. The defect is which phase the milliseconds were attributed to, which no value assertion onCollectorContextcan express.The
targetandwritephases already stamp fromfinallyblocks, with comments in #2811 explaining precisely this reasoning ("stamping only on success would report target:0ms for it — 'the target was free' is the exact misreading this change exists to end"). The probe was the one phase that did not get the treatment.Fix
Hoist
probeWatchout of thetryalongsidecarryKey(the same hoist #2776 already does for the backoff key), track whether the success-path stamp ran, and stamp from thecatchwhen it did not. Guarded by a flag rather than== 0so a throw in the later target or write phases cannot overwrite an honest probe reading with the whole elapsed span.Pinned by a new IL-reachability test: the probe setter must be invoked from inside an exception-handler region on both fetch paths. Proven red on
origin/dev(calls=2 insideExceptionHandler=0, both setters) and green with the fix (calls=3 insideExceptionHandler=1).