Attribute the store probe inside query_store's sql_duration_ms instead of re-basing the column (#3192)

Darling/PerformanceMonitor.Darling.Service/CollectorCostAccumulator.cs

@@ -29,9 +29,19 @@ namespace PerformanceMonitor.Darling.Service;
 /// preserves the TAIL — a single 555s execution is how a collector sticks out on a target, and an hourly
 /// average would hide it.</para>
 ///
-/// <para>sql_ms is a DURATION on the target (it includes waits), not pure CPU — a slow collector may be
-/// latch-waiting rather than burning CPU. It still holds a connection/slot and competes, which is the
-/// point of watching it.</para>
+/// <para>sql_ms is a DURATION (it includes waits), not pure CPU — a slow collector may be latch-waiting
+/// rather than burning CPU. It still holds a connection/slot and competes, which is the point of watching
+/// it.</para>
+///
+/// <para><b>"On the target" is not true of every collector, and the exception is the most expensive one
+/// (#3192).</b> <c>CollectorRunResult.SqlMs</c> is the driver's SQL slice, and on the ENUMERATED path that
+/// slice wraps the per-item watermark refresh and the deferred plan/text fetches — all of which touch the
+/// STORE. For <c>query_store</c> the store probe and write are the majority of it (107,334 of 124,972 ms on
+/// one measured run; 55.4% of <c>plan_fetch</c> and 80.6% of <c>text_fetch</c> fleet-wide per V110). This
+/// series cannot be corrected for it: it aggregates the blended figure in memory and flushes an hourly
+/// total, so there is no phase split to subtract and no source table to re-derive from. That bound is why
+/// the number is left alone and named instead — <c>get_collector_cost</c> carries the caveat and
+/// <c>get_collection_log</c>'s <c>sql_store_ms</c> carries the per-run attribution.</para>
 /// </summary>
 public sealed class CollectorCostAccumulator
 {

Darling/PerformanceMonitor.Darling.Service/DarlingCollectorRunner.cs

@@ -42,6 +42,27 @@ namespace PerformanceMonitor.Darling.Service;
 /// default would let those sites stand in for the ONE success site that must pass the real list, which is
 /// the site whose silence #3161 was filed about. The compiler names every site instead of a grep.
 /// </param>
+/// <param name="SqlMs">
+/// What lands in <c>collection_log.sql_duration_ms</c>: the driver's SQL slice for this run.
+///
+/// <para><b>Not a purely target-side figure, and on the heaviest collector mostly not one (#3192).</b> On
+/// the enumerated path this is the per-item stopwatch around the watermark refresh plus the whole
+/// <c>readItem</c> closure, and for <c>query_store</c> that closure calls
+/// <c>DarlingCollectorRunner.FetchAndStorePlansAsync</c> /
+/// <c>FetchAndStoreQueryTextAsync</c> — each of which probes the STORE for
+/// what content is already held and writes back what came off the target. One measured production run put
+/// 107,334 ms of a 124,972 ms <c>SqlMs</c> in the store against 6,494 ms of plan-plus-text target time, and
+/// the store probe is the largest single term in both fetches fleet-wide (55.4% / 80.6%, V110).</para>
+///
+/// <para><b>Deliberately left blended rather than re-based</b>, and the reason is downstream: this value is
+/// also what <see cref="CollectorCostAccumulator"/> sums into <c>collect.collector_cost</c>, a 90-day hourly
+/// series that carries NO phase split and is built in memory rather than re-aggregated from
+/// <c>collection_log</c>. Subtracting the store terms here would leave 90 days of rows meaning one thing and
+/// every row after meaning another, with nothing in that series able to reconcile them — under a
+/// Collector Cost Regression self-alert whose baseline window is 14 days. The attribution is published
+/// instead of applied: <see cref="Mcp.DarlingDataReader.CollectionLogEntry.SqlStoreMs"/> derives the store
+/// share from the V110 columns, which makes it retroactive to every row that has them.</para>
+/// </param>
 /// <param name="HostNote">
 /// The note the RUNNER authored for a run worth explaining on its collection_log row: the RDS ingest
 /// outcome, the whole-cycle budget, the probe-failure summary, the fan-out bookkeeping. Null (the default)
@@ -2083,8 +2104,11 @@ line and a fetchless collector prints none. */
                             definition.Name, item, server.Config.DisplayName, ex.Message);
                     },
                     cancellationToken,
-                    /* #2150: the per-database wall-clock ceiling. Null for every collector but
-                       query_store, so this argument leaves every other cycle untouched. */
+                    /* #2150: the per-database wall-clock ceiling, straight off the definition, so this
+                       argument leaves a cycle whose collector declares none exactly as it was.
+                       Not "every collector but query_store", which is what this said: four definitions
+                       declare a budget and two of them also enumerate, so plan_correction arrives here
+                       non-null too. */
                     perItemBudget: definition.PerItemWallClockBudget);
 
                 rowsWritten = driverResult.Rows;

Darling/PerformanceMonitor.Darling.Service/DarlingSelfAlertEvaluator.cs

@@ -186,6 +186,21 @@ the daily TOTAL so a cheap-but-frequent collector still cannot trip on a per-run
     /// alone cannot tell that answer from a genuinely new one. Mirrors #2704's
     /// <c>PoisonWaitDelta.CollectionTime</c> fix for the identical shape of bug.</summary>
     private readonly ConcurrentDictionary<string, DateTime> _lastCostRegressionDataPoint = new();
+    /// <summary>
+    /// #3192: the figure this condition fires on is <c>collect.collector_cost.total_sql_ms</c>, which is the
+    /// driver's SQL slice — and on the enumerated path that slice contains the per-item watermark refresh and
+    /// the deferred plan/text fetches, all of which touch the monitoring STORE. So a <c>query_store</c>
+    /// regression here can be the store getting slower rather than the target, and the alert used to say
+    /// flatly that it was "cost on the target". Appended rather than folded into the sentence above so the
+    /// text stays one substitution away from being re-worded, and stated on the alert itself because that is
+    /// where the reader is when the inference gets made.
+    /// </summary>
+    private const string CostIsNotAllTargetSide =
+        "NOTE: on collectors that fetch plan XML or statement text (query_store), part of this figure is the "
+        + "monitoring STORE's own probe and write rather than the monitored server - they run inside the same "
+        + "per-item stopwatch. get_collection_log's sql_store_ms attributes it per run; this series carries no "
+        + "phase split.";
+
     private const double CostRegressionFactor = 2.0;
     private const long CostRegressionBaselineFloorMs = 1000;
     private static readonly TimeSpan CostRegressionBaselineWindow = TimeSpan.FromDays(14);
@@ -697,8 +712,14 @@ await RecordResolutionAsync(new AlertResolution(
     /// FLEET-level (not per-server): the tool's OWN collectors regressing in cost ON the monitored servers
     /// (#2674) — the self-monitoring that makes a collector "sticking out" on a target page us instead of
     /// hiding in a log. Reads <c>collect.collector_cost</c> for per-(server, collector) pairs whose latest
-    /// day's target-side query time exceeds their own baseline (see the thresholds above), fires once per pair
+    /// day's query time exceeds their own baseline (see the thresholds above), fires once per pair
     /// on entry, re-fires on the cooldown while it stays regressed, and resolves the moment it drops back.
+    ///
+    /// <para>"ON the monitored servers" is the series' intent and not always what it measures (#3192): the
+    /// figure rolls up the driver's SQL slice, which on the enumerated path contains the store's own
+    /// plan/text probe and write-back. So a <c>query_store</c> regression here can be the STORE getting
+    /// slower rather than the target, and the fired alert says so — see
+    /// <see cref="CostIsNotAllTargetSide"/>, which exists because this doc and that text have to agree.</para>
     /// Called once per cycle from the worker's hourly store-metrics tick, AFTER the flush that writes the
     /// latest hour. Testable directly with a recording deliverer + a controllable clock.
     /// </summary>
@@ -759,10 +780,10 @@ await FireAsync(
                     detail: $"The '{regression.CollectorName}' collector's OWN query time on {regression.ServerName} rose to " +
                         $"{regression.LatestMsPerRun:N1} ms per run, {ratio:N1}x its {CostRegressionBaselineWindow.TotalDays:N0}-day " +
                         $"baseline of {regression.BaselineMsPerRun:N1} ms per run ({regression.LatestRuns:N0} runs totalling " +
-                        $"{regression.LatestMs:N0} ms so far today). This is the MONITORING TOOL's cost on the target, not the " +
-                        $"server's own workload - each individual run is costing more than it used to. Measured PER RUN (#2846) so " +
+                        $"{regression.LatestMs:N0} ms so far today). This is the MONITORING TOOL's own cost, not the " +
+                        $"server's workload - each individual run is costing more than it used to. Measured PER RUN (#2846) so " +
                         $"a cadence change cannot read as a cost change. get_collector_cost with " +
-                        $"collector_name={regression.CollectorName} shows the trend.",
+                        $"collector_name={regression.CollectorName} shows the trend. {CostIsNotAllTargetSide}",
                     severity: AlertSeverityLevel.Warning,
                     shortMessage: $"{regression.CollectorName} collection cost on {regression.ServerName} is {ratio:N1}x its per-run baseline",
                     numericCurrentValue: regression.LatestMsPerRun,

Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingCollectorCostReader.cs

@@ -22,8 +22,16 @@ namespace PerformanceMonitor.Darling.Service.Mcp;
 ///
 /// <para>Two reads: the ranked fleet summary over a window (total and per-run cost, and the TAIL — the
 /// worst single execution, which is how a collector "sticks out" on a target), and a per-collector daily
-/// trend that both the panel charts and the self-alert's baseline consume. sql_ms is a DURATION on the
-/// target, not pure CPU.</para>
+/// trend that both the panel charts and the self-alert's baseline consume. sql_ms is a DURATION, not pure
+/// CPU.</para>
+///
+/// <para><b>And not reliably a TARGET-side duration either (#3192)</b>, which is why the word is absent
+/// above and from the members below. It rolls up <c>CollectorRunResult.SqlMs</c>, and on the enumerated path
+/// that is the driver's per-item stopwatch around the watermark refresh and the whole <c>readItem</c> closure
+/// — so for <c>query_store</c> the store's plan/text probe and write-back are inside it, measured at 107,334
+/// of 124,972 ms on one production run. This series carries no phase split and is flushed hourly from an
+/// in-memory accumulator, so nothing here can subtract it;
+/// <c>get_collection_log</c>'s <c>sql_store_ms</c> is where the attribution lives.</para>
 /// </summary>
 internal static class DarlingCollectorCostReader
 {
@@ -65,7 +73,8 @@ public sealed record CollectorCostSummaryRow(
         long TotalRows,
         int ServerCount)
     {
-        /// <summary>Average target-side duration per run, over the window. Zero when nothing ran.</summary>
+        /// <summary>Average duration per run, over the window. Zero when nothing ran. NOT purely target-side
+        /// on the plan/text-fetching collectors — see this class's remarks (#3192).</summary>
         public long AvgSqlMs => RunCount > 0 ? TotalSqlMs / RunCount : 0;
     }
 
@@ -120,7 +129,7 @@ public static async Task<List<CollectorCostDailyPoint>> GetTrendAsync(
 
         return rows;
     }
-    /// <summary>A collector whose most-recent day's target-side cost regressed against its own baseline
+    /// <summary>A collector whose most-recent day's cost regressed against its own baseline
     /// (#2674) — the self-alert's detection query. Per (server, collector): latest day's cost PER RUN vs the
     /// run-weighted cost per run of the prior days in the window, returned only when the baseline is
     /// meaningful (total >= floor, and at least 3 prior days so a new collector cannot trip it) and the

Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingDataReader.cs

@@ -125,6 +125,44 @@ phases run on separate stopwatches and tiny skew must not surface as a negative.
             SqlDurationMs is null || SqlOpenMs is null || SqlDrainMs is null
                 ? null
                 : Math.Max(0, SqlDurationMs.Value - SqlOpenMs.Value - SqlDrainMs.Value);
+
+        /// <summary>
+        /// The milliseconds inside <see cref="SqlDurationMs"/> that were spent against the monitoring
+        /// STORE rather than the monitored target (#3192). NULL when this run performed no deferred fetch,
+        /// which is every collector but the plan/text-fetching ones and most runs of even those.
+        ///
+        /// <para><b>Why a target-side column contains store time at all.</b> On the ENUMERATED path the
+        /// driver's per-item stopwatch wraps the whole <c>readItem</c> closure
+        /// (<c>EnumeratedCollectorDriver.RunAsync</c>), and for <c>query_store</c> that closure calls
+        /// <c>FetchAndStorePlansAsync</c> / <c>FetchAndStoreQueryTextAsync</c> — each of which round-trips
+        /// the store to learn what content is already held and then writes back what came off the target.
+        /// Two of those three steps are Postgres, and all three are billed to <c>sql_duration_ms</c>. The
+        /// store probe is the largest single term in both: 55.4% of <c>plan_fetch</c> and 80.6% of
+        /// <c>text_fetch</c> measured over 38.2 h on 42 members (V110), and on one production run 107,334 ms
+        /// of a 124,972 ms "target-side" figure — 86% — against a plan-plus-text target time of 6,494 ms.</para>
+        ///
+        /// <para><b>Probe and write, not target.</b> <c>*FetchTargetMs</c> is genuinely the monitored
+        /// server's work and belongs where it is; only the probe round trip and the write-back are ours.</para>
+        ///
+        /// <para><b>Derived, never stored</b> — the <see cref="SqlOtherMs"/> and #2859 rule: a persisted copy
+        /// could drift from the parent it decomposes, and deriving it means it applies RETROACTIVELY to every
+        /// row written since V110 rather than only to rows written after this change. Nothing about
+        /// <c>sql_duration_ms</c> moves, so the 90-day <c>collector_cost</c> series and the rows already in
+        /// the store stay comparable with each other and with what follows.</para>
+        ///
+        /// <para><b>A FLOOR on the store share, not the whole of it, and the gap is named rather than
+        /// implied.</b> The enumerated path's per-item watermark refresh is also inside the same stopwatch and
+        /// is also a store read — plus a store WRITE on the catch-up/adaptive path
+        /// (<c>CollectorContext.PerItemWatermarkMs</c>) — but that path never sets V108's measured flag, so
+        /// <c>watermark_ms</c> is NULL on precisely the rows this property is non-null on and the component is
+        /// recorded nowhere. So <c>SqlDurationMs - SqlStoreMs</c> is an UPPER bound on target-side time, not
+        /// the target-side time.</para>
+        /// </summary>
+        public double? SqlStoreMs =>
+            PlanFetchProbeMs is null && TextFetchProbeMs is null
+                ? null
+                : (PlanFetchProbeMs ?? 0) + (PlanFetchWriteMs ?? 0)
+                    + (TextFetchProbeMs ?? 0) + (TextFetchWriteMs ?? 0);
     }
 
     /// <summary>One database file's latest I/O snapshot; avg latency is computed by the tool.</summary>