Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

### Added

- **The Query Store tick and the Query Store backfill no longer run against one server at the same time** ([#2165]) - the per-tick `query_store` collection and the [#2058] first-contact backfill were independent loops with no per-server coordination at all, and both do heavy Query Store text extraction. Dogfood evidence from a 4-core multi-tenant box mid-consolidation: a 64 MB backfill slice for a freshly restored database ran concurrently with the tick's collection of a SIBLING database - a 12:50:58 backfill ship overlapping a 12:51:09 tick completion - so roughly 128 MB of extraction was in flight at once on the box least able to afford it. That overlap is not bad luck: a big catalog arriving is exactly what triggers BOTH the backfill and budget-bound tick passes, so the two loops collide precisely when the server is already drowning. A per-server gate now excludes them, in both apps - Darling's `DarlingWorker` keyed by server id, Lite's `RemoteCollectorService` keyed by server - sharing one `QueryStoreServerGate` primitive beside `AbandonableStep` (that one bounds how long a step may hold a loop; this one bounds what may run beside it). **Nothing ever waits, deliberately.** Both sides try-acquire with a zero timeout and SKIP on failure, because these are shared fleet loops: an in-flight slice runs to a 180-300 second abandonment deadline, so a blocking acquire would let one slow server stall collection for the entire fleet - the [#2148] wedge arriving through a lock instead of a hang. **Skipping is safe for this collector specifically** because its window is a watermark ([#1960]): the next pass resumes from the same boundary, so a skipped pass defers rows rather than dropping them - which is also why the gate must not be reused for a collector whose window is wall-clock derived. The "tick wins, backfill defers" bias is realized by CADENCE rather than preemption (stopping a statement already running on the monitored server would mean killing it): the tick retries on its own ~1-minute interval against the backfill's 5, so it recovers five times faster from a collision, and a slice is byte-budgeted so it is short in the healthy case. The backfill takes the gate OUTSIDE its `AbandonableStep`, so an abandoned-but-still-wedged slice keeps the gate closed - the statement is genuinely still running on the server and the tick must keep yielding to it. Built on an interlocked flag rather than a `SemaphoreSlim`: a gate that never waits needs none of what a semaphore provides, and would otherwise own one undisposed kernel object per monitored server forever. Leases are idempotent on dispose, because a stray second `Dispose()` would otherwise clear a flag the OTHER loop had since taken and let both run at once - the exact condition being prevented, reached from the wrong direction.

- **A credential the service cannot decrypt now says why, once, instead of `Key not valid for use in specified state` every 60 seconds forever** ([#2255], second fault from the [#2252] report) - that string is `ProtectedData.Unprotect`'s own, surfaced verbatim into the connect-retry warning. It does not say DPAPI, does not name what failed to decrypt, does not mention that a MACHINE boundary is involved, and reads exactly like SQL Server rejecting a login - which is where the operator looked. **What is actually true**, confirmed from source: both the service's `DarlingSecrets` and the Viewer's `ViewerServerSecret` protect with `DataProtectionScope.LocalMachine` and share the entropy string byte-for-byte (pinned by a round-trip test). LocalMachine means ANY user on the writing machine can decrypt and NO other machine ever can - so this is never a service-account permissions problem and never a user boundary, it is purely a machine boundary. Which settles the open question on the issue: a Viewer on a remote PC cannot produce a credential this service can use, by construction, and the Viewer's own source already documents that single-box limitation. The failure now names the credential and the server, states that this is Windows Data Protection on THIS host and that no credential was ever sent to the server, explains the machine binding, names the remote Viewer as the usual cause, and lists the remedies - all of which run on the service host: re-add from a local Viewer, `--add-server` here, `--encrypt-password` here, or an `env:`/`file:` reference, which is the one option that is not machine-bound at all. The original `CryptographicException` is kept as the inner exception, so nothing is lost for a bug report. **And it stops flooding the log**: a DPAPI failure is permanent by construction, so the full explanation logs at ERROR once per distinct cause and repeats as a single terse line while it persists, with the latch cleared on a successful connect so a cause that is fixed and later recurs is not swallowed as a repeat. Still open on the issue and deliberately not done here: the Add Server dialog refusing at WRITE time when it is not running on the service host - a guard needs a reliable "am I on the service host?" test, which a store connection alone does not establish.

- **The incident readers take an alert's Dedup Key: `get_deadlocks` / `get_deadlock_detail` / `get_blocking` accept `dedup_key`** ([#2159], asked for by @gotqn) - the [#1140] fingerprint already travels end to end and the reporter sets it on their Azure DevOps tickets, but no reader accepted it, so triaging from an alert meant pulling a server+time window and eyeballing rows for the one whose involved objects matched the alert. Slow, and easy to analyze the WRONG deadlock. Paste the key instead and get exactly that incident's graph, queries and stats. The three tools also RETURN a `dedup_key` on every row, so an incident found by browsing correlates back to its alerts and can be handed to another agent as a stable identifier - the [#2138] "agents will read these" direction. **Recomputed on read rather than stored**: the key is a pure function of data the rows already carry, so this covers all retained history immediately, where a new column would have back-filled nothing and left exactly the history an operator triages unsearchable. **It calls the same groupers the alert path calls**, which is the whole design rather than an implementation note - the fingerprint is a SHA-256 over normalized identity members, so any divergence in deriving them yields a different hash and matches NOTHING, and an empty result is indistinguishable from "that incident is outside the window". So the reader builds the same `DeadlockEvent` / `BlockedEvent` the alert builders build and hands them to `DeadlockIncidentGrouper` / `BlockingIncidentGrouper`; pinned by parity tests against the real `AlertContextBuilders` entry points, including the blocking branch that falls back from a contentious object to a normalized query pair. **The trap that made this more than a parameter**: `AlertFingerprint` hashes the SERVER NAME into the key and the alert path passes the DISPLAY name (`Name`, else `Host`), while the MCP resolver returns the STORAGE name (`host[:database][:RO]`) - different strings for any server with a custom display name, and for every registration naming a database or read-only intent. Fingerprinting with the resolved name would have worked on plain hosts and silently returned nothing on exactly the servers most likely to be carefully named, so the readers resolve the display name explicitly. The filter runs over the whole window BEFORE `limit` is applied, because capping first would let `limit` discard the very incident the key names. A no-match answer reports how many rows it examined and names the three causes that look identical from silence - wrong window, wrong server, or a server renamed since the alert fired, which re-keys every fingerprint it has ever produced. `dedup_key` is trailing and optional on all three, so a client written against Lite's parameter contract still calls them correctly; the cross-app pin now asserts Lite's list as a PREFIX, which is the guarantee that was always the point.
Expand Down Expand Up @@ -2719,6 +2721,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
[#2190]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2190
[#2186]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2186
[#2185]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2185
[#2165]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2165
[#2255]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2255
[#2159]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2159
[#2197]: https://github.com/erikdarlingdata/PerformanceMonitor/issues/2197
Expand Down
54 changes: 54 additions & 0 deletions Darling/PerformanceMonitor.Darling.Service/DarlingWorker.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1913,6 +1913,22 @@ private async Task RunQueryStoreBackfillLoopAsync(QueryStoreBackfill backfill, L
abandoned (loudly) and quarantined until its task actually dies, while every other
server's backfill continues. The deadline is a generous multiple of a healthy slice
(statement timeout 60s + store writes), so an abandonment is a defect signal. */
/* #2165: the other half of the gate. Held for the WHOLE slice, and taken outside the
AbandonableStep so an abandoned-but-still-wedged slice keeps the gate closed — the tick must
keep yielding while that statement is genuinely still running on the server, which is exactly
the case the abandonment leaves behind. Zero-wait, so a tick already collecting simply defers
this server's slice to the next five-minute cycle. */
var gate = _queryStoreGates.GetOrAdd(runtime.ServerId, static _ => new QueryStoreServerGate()).TryAcquire();
if (gate is null)
{
_logger.LogInformation(
"query_store backfill slice on '{Server}' deferred — the tick's Query Store collection is running (#2165)",
runtime.Config.DisplayName);
continue;
}

using var backfillGate = gate;

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

The gate is released on Abandoned, even though the guarded statement is still running. This contradicts the stated design ("held for the WHOLE slice... an abandoned-but-still-wedged slice keeps the gate closed") and the PR description's testing claims.

using var backfillGate = gate; disposes at the end of this loop iteration's block — i.e., right after the switch below, regardless of result.Outcome. But per AbandonableStep.RunAsync (PerformanceMonitor.Common/AbandonableStep.cs:132-143), Abandoned means the underlying task (work) is still executing in the background; the step's own _inFlight guard is only cleared later, in work.ContinueWith when the task truly ends.

So on abandonment here:

  1. backfillGate disposes immediately, releasing the per-server QueryStoreServerGate.
  2. The zombie backfill statement keeps running against the monitored server.
  3. On the very next tick (~1 minute later), RunOneAsync's TryAcquire() on the same gate succeeds and launches a fresh query_store collection against the same server.

That's exactly the concurrent-heavy-QS-extraction scenario this PR exists to prevent — and it's most likely to happen precisely when a slice is large enough to hit the 300s abandonment deadline, i.e. exactly the case that matters most.

The gate's lease needs to be handed to the abandoned task and released only when it truly finishes (e.g. threaded through AbandonableStep's own completion, similar to how _inFlight is cleared in work.ContinueWith), not disposed based on RunAsync merely returning.

Note the new Darling_BothLoopsShareOneGateRegistry test only asserts textual ordering ("gate acquired before the step") — it doesn't exercise an actual abandonment, so it doesn't catch this.

Same pattern exists in the Lite counterpart (RemoteCollectorService.QueryStoreBackfill.cs), so this isn't a parity drift — it's a shared bug in both apps.

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

The gate is released as soon as RunAsync returns, not when the slice truly finishes — which reopens exactly the overlap this PR exists to close.

AbandonableStep.RunAsync returns AbandonableStepOutcome.Abandoned while work keeps running in the background; the in-flight guard only clears later, inside work.ContinueWith(...), when the task actually ends (see AbandonableStep.cs lines 101-131). backfillGate here is a using var scoped to this foreach iteration. When the 300s deadline fires, the switch below logs Abandoned and falls off the end of the iteration — disposing backfillGate immediately, while the abandoned backfill statement is still executing against runtime's server.

The very next tick can then acquire the now-free gate (RunOneAsync, line ~3925) and start query_store collection against that same server while the wedged backfill slice is still running underneath it — the ~128 MB-concurrent-extraction scenario from the PR description, reintroduced specifically in the one failure mode (a wedge) where it's most damaging.

The doc comment right above ("an abandoned-but-still-wedged slice keeps the gate closed") and the Abandoned log message both describe behavior the code doesn't actually have.

AbandonableStep doesn't currently expose a "truly finished" hook to release into — only onLateFault, which fires solely on exceptions after abandonment, not on a clean late completion. Fixing this needs either a new completion callback on RunAsync, or capturing work and disposing the gate lease in a ContinueWith on it, rather than via using on the synchronous return path.

Same pattern, same bug, in the Lite twin: Lite/Services/RemoteCollectorService.QueryStoreBackfill.cs around line 99.

Comment on lines +1916 to +1930

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

The gate does not actually stay held through an abandonment — it releases at the exact moment the comment says it must not.

The comment above (and the PR description) claims: "an abandoned-but-still-wedged slice keeps the gate closed... the tick must keep yielding while that statement is genuinely still running on the server."

But AbandonableStep.RunAsync returns Abandoned as soon as the deadline elapses — it does not wait for work to finish:

var finished = await Task.WhenAny(work, Task.Delay(timeout, cancellationToken));
if (finished != work)
{
    ...
    return new AbandonableStepResult(AbandonableStepOutcome.Abandoned);   // work is still running
}

work only truly completes later, in the .ContinueWith continuation that clears AbandonableStep's own _inFlight flag (PerformanceMonitor.Common/AbandonableStep.cs:108-130).

using var backfillGate = gate; is scoped to this loop iteration, so it Dispose()s as soon as RunAsync returns — i.e. immediately on Abandoned, not when the wedged statement actually finishes. Concretely:

  1. A slice wedges past BackfillSliceDeadline (180s) → outcome is Abandoned, loop iteration ends, backfillGate.Dispose() runs — QueryStoreServerGate._taken goes back to 0 — while the abandoned task is still executing the QS extraction query against the monitored server.
  2. On the next tick (~1 min later), RunOneAsync's IsQueryStoreCollector gate calls TryAcquire() on the same per-server gate and succeeds, because it was already released.
  3. The tick's query_store collection now runs concurrently with the still-wedged backfill statement — the exact double-QS-extraction collision ([PERF] Tick QS collection and QS backfill run concurrently against the same server — serialize per server #2165) this PR exists to prevent, and it happens specifically in the case (a genuinely stuck/slow statement) where the collision is worst.

Note _backfillSliceSteps' own IsInFlight guard correctly stays set until work truly ends (that's the whole point of AbandonableStep) — but nothing propagates that same "still running" fact to QueryStoreServerGate, so the new gate doesn't inherit the protection the old guard already had.

The wiring tests (Darling_BothLoopsShareOneGateRegistry / Lite_BothLoopsShareOneGateRegistry in Lite.Tests/QueryStoreServerGateTests.cs) only assert that the gate acquisition line appears before the step textually — they don't (and structurally can't, being text-pin tests) catch that the lease is released too early on the abandoned path. Same issue exists in Lite/Services/RemoteCollectorService.QueryStoreBackfill.cs (the using var backfillGate = gate; there has the identical shape) — flagging both for parity.

A fix likely needs the gate's Dispose() to ride the same completion signal as AbandonableStep's _inFlight clear — e.g. transfer the lease into the onLateFault/continuation path (or a new completion hook on AbandonableStep) instead of disposing it when RunAsync merely returns control to the loop.


var step = _backfillSliceSteps.GetOrAdd(runtime.ServerId, static _ => new AbandonableStep());
var result = await step.RunAsync(
() => backfill.RunServerSliceAsync(runtime, stoppingToken),
Expand Down Expand Up @@ -1951,6 +1967,24 @@ private async Task RunQueryStoreBackfillLoopAsync(QueryStoreBackfill backfill, L
}
}

/// <summary>
/// #2165: per-server gates shared by the tick's Query Store pass and the backfill slice, so the two never
/// run heavy QS text extraction against one server at the same time. Keyed by ServerId and never pruned,
/// like its <see cref="_backfillSliceSteps"/> sibling — one small object per server ever monitored.
///
/// <para>Both loops must resolve the SAME gate instance for a server, which is what makes this one
/// dictionary rather than one per loop. Pinned by a test for that reason.</para>
/// </summary>
private readonly ConcurrentDictionary<int, QueryStoreServerGate> _queryStoreGates = new();

/// <summary>
/// #2165: whether a dispatched collector name is the Query Store collector the gate covers. Compared
/// against the collector's OWN declared name rather than a literal, so renaming the collector cannot
/// silently unhook the gate and let the two loops overlap again.
/// </summary>
internal static bool IsQueryStoreCollector(string collectorName) =>
string.Equals(collectorName, QueryStoreCollector.Instance.Name, StringComparison.OrdinalIgnoreCase);

/// <summary>#2148: per-server abandonment guards for the backfill loop — keyed by ServerId so a
/// removed-and-re-added server reuses its guard (harmless), and a wedged server never blocks its
/// neighbors. Never pruned: one small object per server ever monitored, bounded by fleet size.</summary>
Expand Down Expand Up @@ -3921,6 +3955,26 @@ private async Task<int> RunOneAsync(ServerLoopState server, DarlingCollectorRunn
return 0;
}

/* #2165: the tick's Query Store pass and the backfill slice both do heavy QS text extraction, and
they used to be free to run against the SAME server at once — measured as ~128 MB in flight on a
4-core box, because a big catalog arriving triggers BOTH loops. Gated HERE because this is the one
funnel that has the runtime and the collector name together. Never waits: see QueryStoreServerGate
for why blocking a shared fleet loop would recreate the #2148 wedge through a lock. Skipping is safe
for this collector because its window is watermark-driven (#1960) — the next pass resumes from the
same boundary, so a skipped pass defers rows rather than dropping them. */
using var queryStoreGate = IsQueryStoreCollector(collectorName)
? _queryStoreGates.GetOrAdd(runtime.ServerId, static _ => new QueryStoreServerGate()).TryAcquire()
: QueryStoreServerGate.NotGated;

if (queryStoreGate is null)
{
_logger.LogInformation(
" [{Server}] query_store skipped this tick — its Query Store backfill slice is mid-flight (#2165). " +
"Resumes next tick from the same watermark; no rows are lost.",
server.Config.DisplayName);
return 0;
}

try
{
var result = await run(runner, runtime, cancellationToken);
Expand Down
Loading
Loading