Skip to content

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

Merged
erikdarlingdata merged 3 commits into
devfrom
fix/4012-pg-deadlocks-remask
Sep 23, 2026
Merged

erikdarlingdata merged 3 commits into
devfrom
fix/4012-pg-deadlocks-remask

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 23, 2026 •

Copy link
Copy Markdown
Owner

Closes #4012.

Builds on #4013 (the #4005 normalizer), which is already on dev.

Why

Since #4005 the deadlock collector stores each report's SQL normalized, and every product read normalizes a row stored before it. The rows themselves were never rewritten:

A role with a direct SELECT (#4004 names mcp's grant on every table in collect and config) reads all of them as stored. Erik ruled on the issue: rewrite them with #3915's proven pattern.

What changes

PgDeadlockRemask (new, in Darling.Service) runs one bounded slice per hourly store-maintenance tick. It uses the #3915 store-log remask shape and sits right after that pass in SweepStoreSelfMetricsAsync. It has its own 60 s slice cap and its own catch, so neither a failure nor a slow slice can cost the collector-cost flush.

  • The alerts go first. An incident is found through its report's raw hash, and the report pass replaces that hash, so the report pass starts only after the alert pass reaches the end of the log.
  • Reports. The pager walks (collection_time, server_id, deadlock_hash), the hypertable's partition order, 2,000 rows per slice.
  • Alerts. An incident whose key names a raw report takes the incident the live alert builds for the rewritten report (BuildPgDeadlockIncident), key and object both. This applies in the context, in a per-event row's detail item, and in detail_text.
    • Every other member round-trips through AlertContextDto unchanged.
    • An incident whose report retention already dropped keeps its key, because nothing is left to test that hash against. Its statement is normalized as it stands.
    • Left alone: alerts built from normalized text (report current, or named by a ReportIdentity), SQL Server alerts (64-character lower-case fingerprints), and contexts that do not parse.
    • The UPDATE matches on the row's exact old content, so a row changed in between (a dismissal) is left for a re-read.
  • Findings. These run between the alerts and the reports. The pass uses the read's own normalization (NormalizeStoredDeadlockExemplars, which now reports whether it rewrote the section and can stamp it) and stamps the section sql_normalized, so the read and any later pass leave it as it is.
    • Only a section without the stamp is read.
    • A row is written only while it still holds what the page read.
  • Bounds. Each report, alert and finding write is its own transaction under SET LOCAL statement_timeout = '15s', with the client CommandTimeout 5 s above it.
    • A report whose rewrite fails is counted and left raw. It does not hold the rest of the table back.
    • A scan that left rows raw reads its table through again, at most 3 times per process.
  • No store migration.
  • The AlertReadFailureSurfaceTests census gets the new catch as its 29th stated exemption, the store-log remask's twin.
  • The README's pg_deadlocks row says the older rows are rewritten.

Test plan

  • PgDeadlockRemaskTests (new, 6 tests):

    • Pure: every slice statement carries the parser's raw-hash test.
    • Pure: a raw report becomes what every read shows, under the identity the collector gives the same captured report, and is idempotent.
    • Pure: a legacy alert, Summary and Per-event, becomes byte for byte what the live alert persists for the rewritten report, context and detail_text, and a second pass returns nothing.
    • Pure: only alerts carrying raw text change (report gone, report current, ReportIdentity, SQL Server key, bad JSON).
    • Pure: a pre-pg_deadlocks keeps each deadlock query and the victim statement verbatim, literals included, and returns them to readers and alerts #4005 finding becomes what every read showed and is stamped, so the read leaves it alone and a second pass returns nothing. A finding with no deadlock section is not touched.
  • Live (own scratch store, TimescaleDB hypertable with every chunk compressed). The test plants pre-pg_deadlocks keeps each deadlock query and the victim statement verbatim, literals included, and returns them to readers and alerts #4005 reports: one seen twice across two chunks, one with no victim statement, and one seen raw and again by this build. It also plants a current report and five alerts (summary, per-event, fired-since, report-gone, SQL Server). After the pass:

    • No literal and no raw hash remains in any of the three tables.
    • get_pg_deadlocks/get_pg_deadlock_detail (the reader behind the MCP tools, web dispatch, viewer and alert) and the drill-down's own SQL read every report exactly as before, identity aside. The old at-... name still finds each one.
    • The report seen by both builds reads as one report, times_seen 2.
    • A pre-pg_deadlocks keeps each deadlock query and the victim statement verbatim, literals included, and returns them to readers and alerts #4005 finding reads as it did.
    • The current row, the fired-since alert, the SQL Server alert and a finding with no deadlock section are byte-identical.
    • A second pass rewrites 0 and leaves all three tables byte-identical.
  • Red-watch 1: with the per-event detail-item rewrite removed, the pure alert test and the live test both fail. Restored.

  • Red-watch 2: with the findings stamp removed, the pure findings test and the live test both fail. Restored.

  • Slice cost, measured on PostgreSQL 18.6 + TimescaleDB 2.30.1 with 61 compressed daily chunks and 20,000 raw rows (2,000 reports x 10 sightings, 5 servers):

    Pass Slice Result
    Alerts 500 rows 0.70 s, 500 rewritten
    Reports 2,000 rows first 1.36 s, max 1.88 s; 11 slices, 9.2 s in all, 20,000 rewritten, 0 failed, 0 raw left
    Reports, second pass 2,000 rows 43 ms, 0 rewritten
  • Gates: AlertReadFailureSurfaceTests, TimescaleEnableConnectionSafetyTests, DocCommentHygiene, StartupCommandTimeoutTests, LivePostgresCollectionHygieneTests, LiveCleanupConversionRatchetTests, McpPayloadContractCensusTests, plus PgDeadlockNormalizationTests, StoreLogRemask* and PgTargetDeadlockDrillDown*: all green.

  • Full Darling.Tests with DARLING_TEST_PG, final run: 13,020 run, 32 skipped, 2 failed.

    • Both failures are FleetIdentifierScrubTests, and they are environmental. That test skips every path containing \.claude\, and this lane's worktree sits under .claude\worktrees, so it scanned 0 files.
    • This PR's added lines were checked by hand against both of its patterns: no match.
    • The first full run also caught this PR's live test reusing the connection it handed to TryEnableAsync (TimescaleEnableConnectionSafetyTests). It now goes through LiveTimescaleProbe.
  • Lite untouched (no shared project changed).

🤖 Generated with Claude Code

https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

erikdarlingdata and others added 3 commits September 23, 2026 07:37
…re rewritten in place, so a direct SELECT finds no raw query and no raw-graph hash (#4012)

Since #4005 the collector stores deadlock SQL normalized and every read
normalizes an older row, but the rows themselves kept their raw
victim_statement, graph_text and a deadlock_hash over the raw graph for
pg_deadlocks' 90 days, and a deadlock alert fired before it kept the raw
hash and victim statement in its history row. A role with a direct
SELECT (mcp) read them as stored.

PgDeadlockRemask runs one bounded slice per hourly store-maintenance
tick, the #3915 store-log pattern: alerts first, because an incident
is found through its report's raw hash, then the reports. Only rows
still raw change (the parser's RawGraphHashSql is part of the UPDATE),
each report and alert in its own transaction under a LOCAL 15 s
statement_timeout, so the pass is safe to repeat and safe beside the
collector. A report takes what every read already showed for it and
#4005's identity, so its sightings merge with the new collector's; an
alert takes the incident the live alert builds for the rewritten
report, in its context, its per-event detail item and its detail_text.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
… rewritten in place too (#4012)

A finding persists its deadlock drill-down and prose for 30 days, and one
written before #4005 kept each exemplar's victim statement, fingerprint and
graph raw, with a hash that may be over the raw graph, in analysis_findings,
which the mcp role can SELECT. The same hourly pass now rewrites them between
the alerts and the reports, with the read's own normalization
(NormalizeStoredDeadlockExemplars), and stamps the section sql_normalized so
the read and a later pass leave it as it is. Only a section without the stamp
is read, and a row is written only while it still holds what was read.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
…ites too (#4012)

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
@erikdarlingdata erikdarlingdata changed the title PostgreSQL deadlock reports and alerts stored before #4005 are rewritten in place, so a direct SELECT finds no raw query or raw-graph hash (#4012) 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) Sep 23, 2026
@erikdarlingdata
erikdarlingdata merged commit 40057fc into dev Sep 23, 2026
17 of 20 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/4012-pg-deadlocks-remask branch September 23, 2026 12:06
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…draft while its review round runs

#4020 and #4022 were merged from the UI mid-review on 2026-09-23. A draft
can't be merged there, so the coordinator drafts the PR at review dispatch and
readies it once the review is resolved.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…h database first, and recurring CI failures get a census (#4026)

* Lane orders: the report goes in the PR body, a failure is re-run on a fresh database before it is called pre-existing, and a recurring CI failure gets a census first

- All three of the last lanes were blocked from writing a report file (one
  outside its worktree, two by a policy that subagents return text), so the
  full report now lives in the PR body, or an issue comment for a parked
  item, and the last message is 400 words or fewer.
- A lane filed an issue for a sweep-test failure that was already fixed on
  dev, and called two tests pre-existing that pass on a fresh database.
- The coordinator censuses two days of failed first attempts before fixing a
  flake, and fixes every flake found in one PR.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

* Lane orders: a security PR or irreversible data rewrite is held as a draft while its review round runs

#4020 and #4022 were merged from the UI mid-review on 2026-09-23. A draft
can't be merged there, so the coordinator drafts the PR at review dispatch and
readies it once the review is resolved.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

---------

Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…ra thread-id race, midnight UTC in Darling's daily summary, and the shard class-list parse (#4024)

* The memory-trend grant-join tests pin their seeds past a bucket floor, so a run in a minute's last seconds no longer splits a snapshot from its sample

#4007 put get_memory_trend on clock-aligned buckets. Two tests here still
seeded at UtcNow minus N minutes with 3-6 second offsets, so about one run in
ten crossed a bucket boundary (seen on #4022's Lite shard). Both now start 10
seconds past a five-minute floor, as the Darling twin and this file's third
test already do. Red-watched: a 55-second pin reproduces the CI failure exactly.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

* Two more CI flakes: the Entra thread check reads the caller's id before its await, and Darling's daily-summary test seeds today's run on today after midnight UTC

- EntraDeviceCodeTests.TheAcquisitionIdentityReachesWhatTheAcquisitionAwaits
  read Environment.CurrentManagedThreadId after awaiting a LongRunning task
  with ConfigureAwait(false). The continuation can resume on that dedicated
  thread, so the check compared the thread with itself (dev CI, 06:18Z).
- McpFilterSemanticsLivePostgresTests.DailySummary_StopsPaintingPurgedDaysGreen_AndPublishesTheHorizon
  seeded today's run two minutes back, which lands on yesterday in the first
  two minutes after midnight UTC; it failed beside its Lite twin at about
  00:01Z. Lite got the guard in #3963; this mirrors it.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

* The test shards parse only the runner's JSON line of the class listing, so a dotnet CLI notice on stdout no longer fails a shard before it runs

A dev push at 10:55Z failed Darling PG tests (2) in ConvertFrom-Json:
"Additional text encountered after finished reading JSON content: W",
line 2, i.e. text the dotnet CLI printed after the runner's one-line array.
Both shard steps (Darling, Lite) now keep only the line that starts with
"[" and throw, listing what came back, if there is not exactly one.
Checked locally: the old parse reproduces the CI error on that shape; the
new parse gives the same 401 Lite classes on the real listing.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

---------

Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
… one after verifying it (#4033)

On 2026-09-23 three lane PRs opened ready (#4020, #4022, #4030) were merged
from the UI before the coordinator's verification finished, and #4030 put a
regression on dev (every enabled trace flag hidden; fixed in #4032). A draft
can't be merged from the UI, so a lane now opens a draft, lists anything it
didn't run as an unchecked box, and the coordinator readies it after the
checklist read (and a review round for security PRs).


Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…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
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
… walks pages to its hourly budget, and a failing stage no longer blocks the rest (#4012) (#4036)

* Deadlock re-mask: a missed alert is keyed, never keeps its raw hash; 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

* Deadlock re-mask: narrow the README claim to what is rewritten (pg_log_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

* Deadlock re-mask round 2: runs without a log-hash key (only the alert 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

* Deadlock re-mask round 2: keep FlattenInto's doc block on FlattenInto, 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

* Deadlock re-mask round-2 fixes: the day-later retry runs, and no alert 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

* Deadlock re-mask round-2 fixes: rebuilt incidents are marked, and a gone 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

* Deadlock re-mask round-2 fix: a finding alert is rewritten only from 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

* Deadlock re-mask round-2 fixes: walks page by alert_time and finding_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

* Deadlock re-mask round-2: the moved-row test runs without a key, so only 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

---------

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…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>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant