query_store's sql_duration_ms includes store-side probe time, so the target-vs-store split points the wrong way on the most expensive collector

[erikdarlingdata]

collection_log.sql_duration_ms for the query_store collector includes store-side PostgreSQL probe time, so the product's own "is the target slow or is the store slow" split points the wrong way for its most expensive collector.

Mechanism, verified in source

DarlingCollectorRunner.cs (~1920, ~1945) calls FetchAndStorePlansAsync and FetchAndStoreQueryTextAsync from inside the readItem closure passed to the enumerated driver. EnumeratedCollectorDriver.RunAsync (~673–691) starts sqlSlice = Stopwatch.StartNew(), awaits readItem, and accumulates the elapsed into sqlMs.

So everything the fetches do lands in sql_duration_ms — including QueryStoreFetchProbe.TouchAndProbePlansAsync / TouchAndProbeTextsAsync, which are Npgsql round trips against the store.

Measured

One query_store run on the SQL Server store:

	ms
sql_duration_ms (the "target-side" figure)	124,972
plan probe_ms	54,016
text probe_ms	53,318
probe total — store time inside a target-side number	107,334 (86%)
plan + text target_ms — actually target-side	6,494

Reproduce with get_collection_log at a high limit, filtered to collector == "query_store" rows whose plan_fetch block is non-null.

Why it matters, in the product's own words

get_collector_cost reports roughly 45.8 M ms/day of total_sql_ms for query_store, and its tool description calls that "target-side query DURATION". The get_collection_log projection comment in DarlingMcpDataTools.cs states the intent outright:

A collector slow because the monitored server is slow needs work on that server; one slow because the store is slow needs work here.

For query_store that inference is inverted. A reader concludes the monitored SQL Servers are slow when the time was spent in the monitoring store. This is not a missing metric — it is a metric that answers the opposite of the question it is documented to answer, on the collector where the magnitude is largest.

The trade to decide, rather than pick silently

Option 1 — move the number. Subtract context.PerItemPlanFetchMs + context.PerItemTextFetchMs from the run's sql_duration_ms, or exclude the fetches from the driver's sqlSlice.

Either changes the meaning of a persisted column, so historical rows and the 90-day collector_cost rollups become non-comparable across the change. That has to be stated in the PR body rather than discovered later, and it is the reason this is a decision.

Worth considering as part of option 1: whether store_duration_ms should absorb the probe half instead of the time simply vanishing. The phase split already distinguishes them — probe_ms and write_ms are store, target_ms is target — so the components exist to route it correctly rather than to delete it.

Option 2 — move the documentation. Leave the column and fix the docs plus the MCP tool descriptions so nobody draws the target-side inference. Cheaper and honest, but leaves a number that reads wrong to anyone who does not read the caveat, which is the failure mode that produced this issue.

Neither option is pre-selected. Price both, recommend one, and say what the recommendation costs.

Context

Found while working #3189 (the query_store store probe). #3189's headline framing is wrong for separate reasons documented in that lane's report — its 1.41% "found missing" ratio compares different populations, its probe_ms ÷ probe_ids rate is not rate-like (0.023–13.505 ms/ref, a 587x spread), and its recommended remedy would have caused silent plan-XML loss. Reference #3189 rather than repeating its claims.

This is also the better answer to #3189's "why was this invisible" than the one that issue gives. The probe cost was not merely unaggregated — it was attributed to the monitored servers.