Repository navigation
Deadlock re-mask keys a missed alert instead of leaving its raw hash, walks pages to its hourly budget, and a failing stage no longer blocks the rest (#4012) - #4036
Conversation
…each tick walks pages to its budget; stages run alerts, reports, alert keys, findings and are done only after a clean walk (#4012) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…g_events rows from before #4020 age out per #4004), update the alert-read exemption, and name the keyed-alert tag so the state-key census does not take it for a state key (#4012) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
… keys wait), counts each row's outcome, re-masks finding alerts, finds exemplars anywhere on the chain, retries a given-up stage daily, and binds no raw report hash (#4012, #4035) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…, and give TopVictimFingerprint a block body the member scan reads whole (#4012) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
Round 2: the six findings of review round 1All six are fixed on this branch (commit 4fdaebd and the hygiene commit after it). Closes #4035 too. 1. HIGH: no log-hash key skipped the whole re-mask. 2. MEDIUM: outcomes on a partly finished page were lost. Every slice reports each row's outcome ( 3. MEDIUM: finding alerts were never re-masked. A new last stage,
Writes are guarded by 4. LOW: exemplars off the root. The findings page now filters on 5. LOW: a stage that gave up stayed given up for the life of the process. A given-up stage is reset and walked again from its table's start once 6. LOW (#4035): raw hashes sent as bind parameters.
Measured (rig, TimescaleDB, 120,000 rows over 84 compressed chunks, 5 servers, every row its own raw report, the worst case)
Tests (all in
|
…t is cut from its report (#4012) - The worker gates the re-mask on RemaskProgress.Pending (a stage not done, or one that gave up), not on Done, which a stage that gave up satisfies: gated on Done the daily retry never ran (round-2 finding 1). - The reports wait for the alerts to be done (clean or given up), not merely waiting out a failure, and the alert keys wait for a clean report walk, not a report stage that gave up (round-2 finding 2 a/b). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…one report's key is keyed in the alert stage's own write (#4012) - An incident rebuilt from its raw report carries a RemaskRebuilt4012 property, its own member rather than part of the key, so no walk keys it while its report is still raw; the key, dedupe and every reader are unchanged (round-2 finding 2c). - With the key, the alert stage keys an incident whose report is gone in the same write that normalizes its row, so its raw hash is never bound back to the store; only in a row no pass has rewritten, so an unmarked incident #4022's dev pass rebuilt waits for the alert-key stage (round-2 finding 3). - A live test records every value the re-mask's UPDATEs bind, through triggers, and finds no raw hash or literal. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…the run it was sent for (#4012) The finding alert's exemplar fields other than the SQL are counts and fixed text, so another stored run of the same story, newer but before the alert was recorded, passed as its finding and its exemplars were written over the alert's. The alert's Diagnosis must now read the finding's severity, confidence and window as the formatter rendered them; otherwise the SQL is withheld (round-2 finding 5). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…id, and the finding-alert page skips rows older than #3721 (#4012) - The alert, alert-key and finding-alert walks page config_alert_log by alert_time WITH TIES, and the finding walk pages analysis_findings by finding_id WITH TIES; ctid and xmin are kept only for the write. A row copy that a dismissal, VACUUM FULL or CLUSTER put behind a ctid cursor was never read, and the stage was marked done over it (round-2 finding 4). Each row's callback moves the cursor only once its tie group is finished. - The finding-alert page reads no row recorded before 2026-09-18 (a day before #3721's first commit, for a store that records local time), and that test guards the text tests, so an older row's context is never detoasted (round-2 finding 6). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…nly the alert stage can reach the row (#4012) Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…ntries in their sections (#4080) Adds 42 entries and 42 link refs (#3992, #3995, #3996, #3998, #4001, #4002, #4003, #4007, #4010, #4011, #4013, #4015, #4020, #4022, #4025, #4029, #4030, #4031, #4036, #4038, #4039, #4040, #4044, #4047, #4048, #4049, #4050, #4051, #4055, #4061, #4063, #4064, #4065, #4066, #4067, #4068, #4069, #4070, #4071, #4073, #4074, #4078). Each PR's entry was buffered, and this lands every entry whose PR was merged on origin/dev when it ran. #3989 left 26 entries under bare 'Changed' and 'Fixed' lines above '### Added'. They move into '### Changed' and '### Fixed', below the new entries, and one blank line stays under [Unreleased]. Claude-Session: https://claude.ai/code/session_01Ua31ugERL5DmhFVRtf6keQ Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
Closes #4012.
Closes #4035.
Follow-up to #4022 (already merged to dev): the fixes for its round-1 security review. The rulings are the coordinator's and are applied as given.
Why
The round-1 review of #4022 found:
occurred_atand victim: the offline oracle raw_line_hash and statement_fingerprint are unkeyed hashes a store reader can use to guess the literals they hide #4004 removed. Alerts got missed in two ways. A dismissal UPDATE could move an unvisited row behind the ctid cursor, and that wasn't counted as raced. The rescan cap also marked a stage done anyway.drill_down_json, and a stage error retried hourly with no cap.pg_log_eventsrows from before Log-event hashes are keyed with a per-store secret the service keeps outside the store, so a store reader can no longer test guesses at the literals they hide (#4004) #4020 still hold an unkeyedraw_line_hash.log_min_duration_statement.What changes
1. A missed alert is keyed, never keeps its raw hash (
PgLogHashKey,PgDeadlockRemask.RemaskAlert)PgLogHashKeyderives a third subkey under a new domain label,darling-pg-deadlock-alert-key-v1, using Log-event hashes are keyed with a per-store secret the service keeps outside the store, so a store reader can no longer test guesses at the literals they hide (#4004) #4020's existing derivation. It is not theraw_line_hashsubkey. The new method isDeadlockAlertKey(key)and returnshk-plus 32 hex characters.hk-tag is never a report hash's shape, so a key that has been keyed once isn't resolved again.detail_text. Two alerts that shared a key still share one, and there's no oracle.PgLogHashKey's public API. The worker reads it fromrunner.LogHashKey, which is a new internal getter on the runner, at the store-metrics tick.DarlingLogHashKeyFile.cs,DarlingManagedRoles.csand the key load site are untouched (lane R).Done only after a clean walk
MaxRescansPerProcess.2. Pages to the budget; the cursor survives a cancel (
PgDeadlockRemask.RunAsync)SliceBudget.RunAsyncends quietly on its own cancel.RemaskProgress), like The store's statement statistics survive their review: ALTER SYSTEM advice that bricked the store, a reader filter any grantee could switch off, secrets in slow_statement, a probe that failed for non-superuser owners, and 20 more (#3899) #3915's store-log cursor. The measured rescan cost is in the test plan.3. Order, a findings filter, and a failure cap
root_fact_keyisPG_DEADLOCK_RATEorANOMALY_PG_DEADLOCK_RATE, the only roots the deadlock exemplar section is attached to. That is a plain column, so no other finding's drill-down is detoasted. I filtered onroot_fact_keyrather thancategorybecause the section is attached by root fact, which is the exact discriminator.MaxConsecutiveStageFailures= 4. Each failure is logged. The stage then skips 0, 1 and 3 ticks, and on the fourth failure stops for the process.4. Narrowed claim (README
pg_deadlocksrow,PgDeadlockRemaskclass doc)pg_log_eventsdeadlock ERROR rows from before Log-event hashes are keyed with a per-store secret the service keeps outside the store, so a store reader can no longer test guesses at the literals they hide (#4004) #4020 keep their unkeyedraw_line_hashuntil the table's 30-day retention drops them. That is raw_line_hash and statement_fingerprint are unkeyed hashes a store reader can use to guess the literals they hide #4004's ruling, since re-keying them would split their dedupe identity.5. Identity match: nothing more is reconstructible (comment in
RemaskReport, pinned by a test)93787e8c~1'sFromEntry), including the query's own. SoLIMIT<tab>50is stored asLIMIT50, one identifier that keeps its digits, as every read already shows it. The live read givesLIMIT ?. Where the tab stood isn't in the stored text.DetailComplete. The old collector stored a report cut at a chunk boundary and kept no proof it was whole. The rewrite keepscomplete = false, which fails closed: claimingcompletefor a cut report is Log messages show as PostgreSQL wrote them, the SQL in them stays normalized, and one statement's text never decides how another's is read (#3944) #3996's out-of-step read, where a literal is kept as a word.6. No raw text as a parameter
ctidplusxmin(an NpgsqlXidparameter).victim_statementcomparison. The raw-hash predicate already proves the row still holds the graph the page read, and the victim statement is that graph's own victim query.Test plan
PgDeadlockRemaskTests+PgLogHashKeyTests: 22/22 (live on PG 18.6 + TimescaleDB 2.30.1).detail_textincluded, stable, store-specific, not the raw-line subkey, not a report-hash shape;hk-key;[2,2,3,3,3,3,4,4], capped, 8 warnings (alerts plus alert keys);OnlyAnAlertCarryingRawText_IsRewritten,RunAsync_WalksEveryPage_InOrder_AndIsDoneOnlyAfterACleanWalkandRawReportsAndAlerts_AreRewrittenOnce_.... Restored, all pass.origin/dev, on a freshdarlingtest: 13,040 total, 2 failed, 33 skipped. Both failures were mine, and both are fixed:CollectorStateContractTests.EveryDeclaredStateKeyPrefixHasAPruneVerdict. My constant was namedDeadlockAlertKeyPrefix, and that census treats every public*KeyPrefixconst as a collector-state key prefix. It is an HMAC value's tag, not a state key, so it is renamedDeadlockAlertKeyTag; the census itself is not weakened.RefreshCeilingStalenessTests.TheSpacingFinding_IsCalledPerLightRefresh_OnTheSameWatch. Mysededits left the working copy ofDarlingWorker.cswith LF endings, and the test searches for CRLF. A checkout under.gitattributesgives CRLF, as CI's does. After re-checkout it passes.AlertReadFailureSurfaceTestsandStoreToastAndCheckpointerTestsclasses, 143/143.AlertReadFailureSurfaceTests' exemption key is updated to the worker catch's renamed message, with the same reason plus the stage cap.For the coordinator to double-check
root_fact_key, notcategory(item 3).runner.LogHashKeyis read at the store-metrics tick, deliberately away from lane R's load site.Round 2: the six findings of review round 1
All six are fixed on this branch (commit 4fdaebd and the hygiene commit after it). Closes #4035 too.
1. HIGH: no log-hash key skipped the whole re-mask.
RunAsynctakes a nullable key. The alerts, reports, findings and finding-alerts stages always run. Only the alert-key stage waits for a key: it logs one warning and stays pending, never done and never given up. The worker hands its key over as it stands, with no gate of its own (_pgDeadlockRemaskNoKeyWarnedis gone; the once-only flag lives inRemaskProgress).2. MEDIUM: outcomes on a partly finished page were lost. Every slice reports each row's outcome (
Unchanged,Rewritten,Left) through its per-row callback, and the stage counts it there. A walk is the clean one only when it counted no rewrite, left nothing, and no cancel or failure cut it short (WalkInterrupted). The hand-setWalkRewritten = 10is gone from the test.3. MEDIUM: finding alerts were never re-masked. A new last stage,
finding alert, pagesconfig_alert_logrows whose metric starts withAnalysis:and whose context carries aPg Deadlock Exemplarsitem flattened before #4005 (noSql Normalizedfield and no withheld marker). The same statement finds the finding by server, category and the 8-character story-hash prefix the metric name carries: the newest one analysed within a day before the alert. Then:FindingMessageFormatter.DrillDownItem, now shared) and stampedSql Normalized. The victim the advice prose names is replaced by the normalized fingerprint.ExemplarsandNoteare withheld as(withheld: stored before #4005 with its SQL raw), and so is the victim in the prose. This fails closed.Writes are guarded by
ctidandxmin, and the stage follows the same clean-walk rule. The advice item's body (the frozen story prose) also named the raw fingerprint. The review did not list it, and it is covered here.4. LOW: exemplars off the root. The findings page now filters on
string_to_array(story_path, ' → ') && ARRAY[PG_DEADLOCK_RATE, its anomaly]. That test sits inside aCASE, so no other finding's drill-down is detoasted.5. LOW: a stage that gave up stayed given up for the life of the process. A given-up stage is reset and walked again from its table's start once
RetryGivenUpAfter(1 day) has passed.6. LOW (#4035): raw hashes sent as bind parameters.
ctidplusxmincannot work forpg_deadlocks. On a compressed chunk,SELECT ctid, xminfails withtransparent decompression only supports tableoid system column(rig, TimescaleDB). So the report walk pages by(collection_time, server_id)withFETCH FIRST n ROWS WITH TIES. A page never splits a batch, and the cursor moves only when a batch is finished. Alerts, findings and finding alerts stay onctidplusxmin.collection_time,occurred_at,victim_pidand the raw test. If two raw reports share that place, the statement fails with21000and the report is countedLeft, instead of guessing.occurred_at = $3 AND victim_pid = $4as plain equalities, on purpose. On the rig, an UPDATE keyed only by the subquery hittuple decompression limit exceeded: TimescaleDB filters compressed batches only by constant or parameter quals. With the equalities,EXPLAIN ANALYZEshowed 1 of 201 batches decompressed. A report with a NULL timestamp or pid is rewritten in its own batch (ReportUpdateOwnBatchSql).DedupKeys out ofcontext_jsonwithregexp_matches. There is no JSON parse, so a malformed context cannot fail the page.Measured (rig, TimescaleDB, 120,000 rows over 84 compressed chunks, 5 servers, every row its own raw report, the worst case)
Tests (all in
PgDeadlockRemaskTests; every class in the file run)NoStatementBindsARawReportHash(Lite overview: show Online/Offline status #6)TheWorkerRunsTheRemaskWithOrWithoutAKey(Add check for updates feature #1, source pin)WithoutAKey_EveryStageButTheAlertKeysRuns(Add check for updates feature #1)ACancelMidPage_ThenACompletedWalk_NeverLeavesTheStageDoneOverARawRow(Lite overview: show Online/Offline status for servers #2)AFindingAlert_IsRewrittenFromItsFinding_OrWithheld(Add check for updates feature #3)AFindingWhoseDeadlockFactIsOffTheRoot_IsRewrittenToo(Add possibility to exclude WAITFOR() from Top Queries view #4)AFailingStage_...(Lite: collector health status bar shows global errors instead of per-server #5, the daily retry) andABudgetCancel_...(the new cursor, no hand-set count).RunAsyncthrowing on a null key, plus the worker's gate, failsWithoutAKey_...andTheWorkerRuns....ACancelMidPage_...(expected 0 raw rows, found 1, with the stage done).AFindingAlert_....AFindingWhoseDeadlockFactIsOffTheRoot_...and the SQL pin.AFailingStage_....Darling.TestsandLite.Testsboth build with 0 warnings.For the coordinator to double-check
ctidplusxmin, which a compressed chunk refuses (the error is quoted above). The replacement is a batch cursor plus a server-side anchor.MaxRescansPerProcesswalks and retries a day later.InternalsVisibleTo PerformanceMonitor.Darling.Servicewas added, so the stage sharesDrillDownItem/DrillDownHeading.BuildContextnow callsDrillDownItem, with no change in behaviour.4036-reported.txtis rewritten for the new behaviour.🤖 Generated with Claude Code
https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
Round-2 fixes
Lane V's fix pass for review round 2, the last round. Commits 1642059..c81507c, plus a merge of dev (head 6576320). Every fix has a regression test, and each test was proven once by reverting its fix.
1 (MEDIUM): the day-later retry now runs. The worker gated on
RemaskProgress.Done, which a stage that gave up also satisfies. Once every stage had finished or given up,RunAsyncwas never called again, so the daily reset never ran. The worker now gates onRemaskProgress.Pending(Stages.Any(s => !s.Done || s.GaveUp)). While no retry is due, every stage is skipped without a statement.AFailingStage_BacksOff_IsCapped_AndDoesNotStarveTheOthersnow ticks throughTickAsTheWorkerAsync, the worker's own gate.TheWorkerRunsTheRemaskWithOrWithoutAKeypins the worker toif (_pgDeadlockRemask.Pending).Pending => !Donethe test fails.2 (MEDIUM): an alert can no longer be cut from its report.
Reports.Done && !Reports.GaveUp. Test:TheAlertKeys_WaitForAReportStageThatGaveUp. Red on the old gate: the alert-key stage walked and keyed the rebuilt identity.Alerts.Done(a clean walk or a give-up), never for an alert stage that is only waiting out a failure. Test:AnAlertStageFailure_DoesNotLetTheReportsRunAheadOfIt. Red on the old gate. The failing-stage test now shows the reports starting on the tick the alert stage gives up."RemaskRebuilt4012":trueappended to its incident object. Why this marker:hk-...), and no key's value changes."DedupKey":"..."LIKE match still finds it, because the marker follows the incident's other members; this is pinned withContextJsonContainsDedupKey.AlertIncidentDtodoesn't map it, and nothing in the product setsUnmappedMemberHandling(grepped), so System.Text.Json skips it. That means no store migration, and no change to a shared DTO (PerformanceMonitor.Notifications, which Lite also builds).ARebuiltIncident_IsMarked_AndNoWalkKeysIt. Red with the marker check removed.reportsMayBeRaw: true), an unmarked key that finds no report is keyed only in a row no pass has rewritten: one with an incident that still resolves to a raw report, or that still carries a statement to normalize. A row PostgreSQL deadlock reports, alerts and findings stored before #4005 are rewritten in place, so a direct SELECT finds no raw query or raw-graph hash (#4012) #4022 rewrote has neither, so it isn't written at all, and it waits for the alert-key stage. Test:AnUnmarkedRebuiltRow_WaitsForTheAlertKeys. Red without the rule.3 (LOW, #4035): with a key, no raw hash is bound as a value. The alert stage now receives the key. It keys an unmarked unresolvable incident in the same write that normalizes its row.
NoRemaskWriteBindsARawReportHashAsAValueinstalls BEFORE UPDATE triggers onconfig_alert_logandpg_deadlocks. They record every value the re-mask's UPDATEs write, which are exactly the values bound toSET ... = $n. The test finds no raw hash and no literal among them. Red when the alert stage gets no key.$1/$2, because there is nothing to key it with. I did not build an in-SQL rewrite for this case (a per-row placeholder-restore UPDATE). The service already logs the no-key state at start-up, and the hash stays in the row itself until a key exists either way.4 (LOW): walks page by
alert_timeorfinding_id, never by ctid.config_alert_log(the alert, alert-key and finding-alert walks) pages byalert_time,FETCH FIRST n ROWS WITH TIES.analysis_findingspages byfinding_idWITH TIES.ctid+xminremain only in the writes.pg_deadlocks, which is compressed, was already paged bycollection_timeand is unchanged.AnAlertMovedBehindTheWalk_IsStillReached. CLUSTER, run after the walk's first row, moves a raw alert to (0,1), behind a full page. The test runs without a key, so the alert-key stage can't rescue the row. Red on 478b8fa (the commit before the paging change):Walkswas 1, meaning the walk declared itself clean with the row still raw.5 (LOW): a finding alert is rewritten only from the run it was sent for. The page also returns the finding's
severity,confidenceandtime_range_start/time_range_end. The alert's Diagnosis item must match them:F2. A decimal comma is accepted, since the service formatted them in its own culture.utimestamps, or no Window when the finding has no range.AFindingAlert_WhoseStoryRanAgain_IsWithheld_NotRewrittenFromTheOtherRun, with a different severity, a different window, and a matching control. Red with the check disabled.6 (LOW): the finding-alert page skips rows older than #3721.
alert_time >= '2026-09-18'. The same test sits inside the CASE that guardsstrpos, so an older row's context is never detoasted.alert_timecarries no zone, so it holds for stores recording local time from UTC-12 to UTC+14.Measured on the rig (PostgreSQL 18, TimescaleDB 2.30.1), in the
probedatabase:Analysis:rows with ~6 KB contexts.alert_time. The saving is the TOAST reads of old rows.ReportUpdateSqlshape): apg_deadlockshypertable of 518,400 raw reports, 40 servers, 90 daily chunks, 87 of them compressed with segmentbyserver_id.server_id(segmentby) andcollection_timemin/max, then filters that server's later batches in memory byoccurred_at/victim_pid. It reads every later batch of that server, so the cost grows with one server's rows after the report, not with the table.timescaledb.max_tuples_decompressed_per_dml_transactionwhere that setting exists. Before 2.11 an UPDATE on a compressed chunk is refused; the report stage counts that report as left, gives up after its rescans, and retries daily.Round 2's clean items, re-confirmed:
WithoutAKey_EveryStageButTheAlertKeysRunspasses. The reports now wait for the alerts, but that is ordering and needs no key.ACancelMidPage_ThenACompletedWalk...andABudgetCancel...pass, and the new cursors move only at a closed tie group.Tests:
PgDeadlockRemaskTests(the file's only test class) 24/24 on the rig, live.Darling/, and no shared project changed.For the coordinator to double-check:
reportsMayBeRaw). Read the first loop inRemaskAlert.FindingAlertSectionSince= 2026-09-18.4036-reported.txtis updated: the retry and bound-value claims are now true, the no-bind claim is scoped to "with a log-hash key", and the two new outcomes are added.