Collapse verb narrows its slice adaptively instead of dying at the timeout - #2132
Conversation
…meout #2105 round three: with the decompression rail lifted, ghauan's run made it ~15 minutes in and died at the new wall — a day-wide stage aggregation on a store carrying 60k split intervals blows through the 15-minute per-statement timeout, surfacing as the same bare stream exception. The verb's fixed day-per-slice loop now runs the shared AdaptiveSpan schedule (24h base): a failed slice halves the window and retries the SAME start, announced with a [RETRY] line naming the error so narrowing reads as progress; a completed slice resets to full width; only a slice that fails at the ~22-minute floor gives up to the existing idempotent re-run message. Healthy stores still repair in a handful of day slices. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
| try | ||
| { | ||
| removed += await QueryStoreSliceRepair.CollapseSliceAsync( | ||
| connection, sliceStart, sliceEnd, cancellationToken); | ||
|
|
||
| consecutiveFailures = 0; | ||
| sliceStart = sliceEnd; | ||
| } | ||
| } | ||
| catch (Exception ex) when (ex is not OperationCanceledException) | ||
| { | ||
| /* Each slice is its own transaction, so earlier slices are already committed and are not lost — | ||
| and the collapse is idempotent, so re-running picks up where this stopped. */ | ||
| error.WriteLine($" The collapse failed after {removed:N0} row(s); the failing slice was rolled back: {ex.Message}"); | ||
| error.WriteLine(" Slices already committed are safe. Re-run to continue — the repair is idempotent."); | ||
| return 1; | ||
| catch (Exception ex) when (ex is not OperationCanceledException) |
There was a problem hiding this comment.
Retry reuses a connection that may already be dead.
On failure the loop continues and calls CollapseSliceAsync again on the same connection (line 3037-3038). But the failure mode this PR exists to survive is SliceStatementTimeoutSeconds (900s) expiring — and per the doc comment on that constant a few lines up in QueryStoreSliceRepair.cs ("The failure read as 'Exception while reading from stream' ... which is how an Npgsql command timeout surfaces"), that's a bare stream exception, not a clean 57014 canceling statement due to user request. That's the signature of Npgsql's cancel-on-timeout failing to land and force-closing/breaking the connection rather than cleanly cancelling server-side.
If the connection is actually broken at that point, the next iteration's BeginTransactionAsync fails immediately — not because the narrower window still doesn't fit, but because there's no usable connection. The loop would then burn through all six halving steps almost instantly on local connection errors and give up, without the narrower windows ever really being tried against Postgres — quietly defeating the fix in exactly the scenario (a real statement timeout) it's meant to handle.
The PR description notes this exact retry path "can't be provoked deterministically in a live test," so it looks untested end-to-end. Worth checking connection.FullState/State and reopening (or just opening a fresh connection per slice, like QueryStoreBackfill.cs does per-attempt) before retrying, and verifying against a real 900s timeout before shipping — this repo already treats "a dead connection poisons every collector" as a known failure class elsewhere (DarlingWorker.cs).
| var span = QueryStoreBackfillState.AdaptiveSpan(fullWidth, consecutiveFailures); | ||
| var sliceEnd = sliceStart + span; | ||
| if (sliceEnd > collapseEnd) | ||
| { | ||
| var sliceEnd = sliceStart.AddDays(1); | ||
| if (sliceEnd > collapseEnd) | ||
| { | ||
| sliceEnd = collapseEnd; | ||
| } | ||
| sliceEnd = collapseEnd; | ||
| } | ||
|
|
||
| try | ||
| { | ||
| removed += await QueryStoreSliceRepair.CollapseSliceAsync( | ||
| connection, sliceStart, sliceEnd, cancellationToken); | ||
|
|
||
| consecutiveFailures = 0; | ||
| sliceStart = sliceEnd; | ||
| } | ||
| } | ||
| catch (Exception ex) when (ex is not OperationCanceledException) | ||
| { | ||
| /* Each slice is its own transaction, so earlier slices are already committed and are not lost — | ||
| and the collapse is idempotent, so re-running picks up where this stopped. */ | ||
| error.WriteLine($" The collapse failed after {removed:N0} row(s); the failing slice was rolled back: {ex.Message}"); | ||
| error.WriteLine(" Slices already committed are safe. Re-run to continue — the repair is idempotent."); | ||
| return 1; | ||
| catch (Exception ex) when (ex is not OperationCanceledException) | ||
| { | ||
| var narrower = QueryStoreBackfillState.AdaptiveSpan(fullWidth, consecutiveFailures + 1); | ||
| if (narrower < span) | ||
| { | ||
| consecutiveFailures++; | ||
| output.WriteLine($" [RETRY] slice {sliceStart:yyyy-MM-dd HH:mm} +{span.TotalMinutes:F0}m failed ({ex.Message.Split('\n')[0].TrimEnd('\r')}); narrowing to {narrower.TotalMinutes:F0}m and retrying."); |
There was a problem hiding this comment.
Minor: span is the nominal AdaptiveSpan width, but sliceEnd gets clamped to collapseEnd on the range's final iteration(s) (lines 3030-3033). If a clamped (shorter) final slice fails, this [RETRY] line and the give-up message on line 3056 both print span.TotalMinutes — the un-clamped nominal width, not the actual queried span (e.g. logging "+1440m" when the real slice that failed only covered a few hours). Undercuts the fix's own goal of giving the operator an accurate picture of what happened — consider logging sliceEnd - sliceStart instead of span.
Review summaryScope: this PR only touches Logic of the adaptive halving loop checks out. Walked through Two findings left as inline comments:
No security concerns (all slice queries are parameterized; the only interpolated identifier is the private |
…atches The statement-timeout failure this loop survives surfaces as a broken stream, not a clean server-side cancel — the connection underneath is very likely dead, and retrying on it would fail instantly through every halving step, making the fix a no-op in exactly the field case it targets. The retry path now cycles the connection (close is safe on a broken one; reopen draws a fresh physical connection; nothing session-scoped is lost — the slice's SET LOCAL and timeouts are transaction/command scoped). And the retry decision plus both operator messages now speak the width the slice ACTUALLY covered: a clamped final slice can be narrower than several nominal halving steps, so the loop skips steps that would rerun the identical window, and no message claims +1440m for a slice that covered two hours. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
Both catches were real — thank you, the first one would have made this fix a no-op in exactly the field case it targets. Fixed in ce45eed:
|
| await connection.CloseAsync(); | ||
| await connection.OpenAsync(cancellationToken); |
There was a problem hiding this comment.
CloseAsync/OpenAsync here aren't wrapped in a try/catch, unlike the CollapseSliceAsync call above. If the reopen itself fails (very plausible right after detecting the connection is likely dead — e.g. the network blip is ongoing, or Postgres restarted), the NpgsqlException/SocketException propagates out of this catch block, out of CollapseLegacySlicesAsync, and up through Program.cs's top-level statements — which have no surrounding try/catch around this verb's dispatch (line ~273). The process crashes with an unhandled-exception stack trace instead of the clean "already-committed rows are safe, re-run is idempotent" message this whole method is otherwise careful to give.
Contrast with the backfill worker's analogous adaptive-shrink path (QueryStoreBackfill.RunSliceAsync): it opens a new connection per attempt inside a scope the caller's pre-existing top-level catch-and-log-and-continue already covers, so a failed reopen there just fails that one background tick. This CLI verb has no such safety net — it's a one-shot invocation.
Worth wrapping the reopen in its own try/catch that falls through to the same error.WriteLine(...); return 1; idempotent-rerun message, so a dead-connection reopen failure degrades gracefully like every other failure mode this verb handles.
| var next = consecutiveFailures + 1; | ||
| var narrower = QueryStoreBackfillState.AdaptiveSpan(fullWidth, next); | ||
| while (narrower >= actualWidth) | ||
| { | ||
| var evenNarrower = QueryStoreBackfillState.AdaptiveSpan(fullWidth, next + 1); | ||
| if (evenNarrower >= narrower) | ||
| { | ||
| break; /* the adaptive floor — no step narrows this slice */ | ||
| } | ||
|
|
||
| next++; | ||
| narrower = evenNarrower; | ||
| } | ||
|
|
||
| if (narrower < actualWidth) |
There was a problem hiding this comment.
Minor resilience gap: QueryStoreBackfillState.AdaptiveSpan can never return less than the ~22.5-minute floor (24h base, 6 halvings), so whenever actualWidth is already ≤ that floor, this search always ends with narrower >= actualWidth and falls straight to the give-up branch — with zero retry attempts, not "retry down to the floor then give up."
That's not a rare edge case: the last slice of essentially every run is a leftover partial-day clamp (sliceEnd = collapseEnd), and there's no reason that leftover is ≥22.5 minutes — it can just as easily be 5 or 10 minutes. If that small tail slice hits any transient failure (a network blip, not an actual statement timeout — it's far too narrow to hit the 900s wall), it skips the connection-cycling retry entirely on its very first failure, even though the reconnect fix is motivated by exactly that kind of transient/connection-level failure and doesn't depend on narrowing actually happening.
It still degrades gracefully (the existing idempotent-rerun message), so this isn't data-unsafe, but it does mean the new retry mechanism silently doesn't apply to what's usually the last slice of the run. Might be worth special-casing "already at/below the floor" to retry once at the same width on a fresh connection before giving up, rather than giving up unconditionally.
Separately: this narrowing-selection logic is pure and would be easy to unit test in isolation (e.g. NextNarrowerSpan(fullWidth, consecutiveFailures, actualWidth)) without needing a live timeout — that's likely how this gap would get caught, since the PR's own live tests can't provoke it deterministically.
|
Reviewed the adaptive-slicing change in
Lite/Darling parity: no drift here — Lite's Query Store slice-repair ( No security or SQL-injection concerns (all Npgsql params, no string-built SQL from user input in this diff). No missing-index findings offered, per instructions. |
…ing decision Round-two review catches, both real: - A failed REOPEN during the retry escaped the catch and crashed the one-shot verb with a raw stack trace — it now degrades to the same clean idempotent-rerun message as every other failure, naming both the slice failure and the reopen failure. - A slice at/below the ~22.5m adaptive floor (usually the clamped final tail, whose width is arbitrary) gave up on its FIRST failure with zero retries — exempting the run's usual last slice from the fresh-connection retry entirely. It now gets ONE same-width retry on a fresh connection before the give-up. The narrowing decision is extracted as the pure NextNarrowingFailureCount (per the review's suggestion) and pinned: first-halving step, clamped-tail step-skipping, and the at/below-floor null that hands over to the same-width retry. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
Round two both taken, in 0eb0731:
|
|
Reviewed the diff ( A few notes, none blocking:
No correctness, security, or SQL-injection issues found; the slice bounds stay parameterized ( |
#2105 round three (ghauan, same store). With the decompression rail lifted by #2127, their run survived past the old four-minute wall and died ~15 minutes in with the same bare stream exception — which is exactly
SliceStatementTimeoutSeconds(900s): a day-wide stage aggregation on a store carrying 60,654 split intervals doesn't fit the statement timeout, and the verb's slice width was a fixedAddDays(1).The fix
The slice loop now runs the same shared adaptive schedule the Query Store backfill worker shipped this week (
QueryStoreBackfillState.AdaptiveSpan, 24h base):[RETRY]line that names the error — narrowing reads as progress, not a hang;Raising the timeout instead would be the wrong lever: the slice transaction holds chunk locks the live service's compression jobs also want, and 15 minutes is already generous — the right response to "too big to fit" is a smaller bite, the exact design conclusion #2125 reached for the live path.
Tests
The halving schedule itself is the already-pinned
AdaptiveSpan(floor and cap pins shipped with #2125). The verb's happy path stays covered byCollapseVerb_DryRunsWithoutChanging_ThenRepairs_ThenFindsNothingLeft; the retry arm is driven by real statement timeouts that can't be provoked deterministically in a live test without multi-minute CI stalls, so its correctness rides the shared policy's pins plus the loop's structure.🤖 Generated with Claude Code