Repository navigation
Say which transport recovers a truncated deadlock report, and pin what the other loses (#3009) - #3028
Conversation
PgDeadlockLogParser.Extract justified skipping an unparseable block with "it will be read whole on the next pass, because the window overlaps." That holds for the pg_read_file route and not for the RDS log-API route, which is consume-once: RdsLogSource keeps a resume marker per (instance, file) and DownloadDBLogFilePortion starts the next call where the last one stopped, so a report straddling a chunk boundary is never completed. Extract's remarks now name the asymmetry and both loss shapes. A chunk ending before DETAIL: matches nothing and the report is lost whole. A chunk ending mid-DETAIL still matches, because the continuation group accepts however many tab-indented lines arrived, so a row lands carrying only the participants, resources and statements inside the chunk. The same correction goes to FromBlock's comment, to both places the dedupe hash explained itself by an overlap the managed route does not have, and to V103's rung doc, which asserted the overlap for both transports. Two pins carry the shapes as distinct cases, because they fail in opposite directions and a test covering only the first would pass a fix that left the second. The mid-DETAIL pin also records why a row cannot be checked against its own graph: ParticipantCount is counted from the same edges GraphText holds, so a fragment lowers both together. What a fragment does leave is a participant count exceeding its edge count, which a whole report -- one edge per participant -- cannot produce.
|
Reviewed. This is a comment/test-only PR (confirmed via Two things worth a look: 1. The fix is incomplete — the same corrected claim still appears twice, unfixed, elsewhere in the codebase. The PR's whole point is that "window overlaps → a report cut at the edge is whole on the next read" is false for the RDS log-API route. That claim was corrected in
I couldn't leave inline comments on these since they're outside this PR's diff, but they're real drift given the PR's own stated goal (I posted an inline nit on the one in-diff issue I found, a style nit in the new test file's 2. The PR body includes a specific CHANGELOG entry to add under No correctness, parity, security, or performance issues found — this doesn't touch T-SQL, and Lite has no counterpart file for any of the three changed files (the parser is shared collector code with one shared test project), so there's no Lite/Darling drift here beyond the two stale-comment spots above. |
Three more copies of the recovery guarantee, two of them found in review. PgDeadlocksCollector's class doc was the worst of them: it names both routes in one sentence and then asserts the overlapping window for the pair. V104's index rationale asserts it twenty lines from the V103 doc corrected in the previous commit, and the deadlock_hash column comment in the definition both routes write through explained itself the same way. The first sweep missed all three because it matched phrases case-sensitively and the collector spells it "OVERLAPS". Extract's closing paragraph said RdsLogSource "advances and persists its resume marker as a side effect of the fetch, before this parser is reached," so a timezone refusal lost the readable siblings in its window. #3008 moved that commit after the write, and RdsDeadlockIngestor now keeps the parse ahead of the commit specifically so a refusal leaves without it -- the next cycle asks for the same window and the siblings survive. That paragraph now says so, and says why the truncation above is the case #3008 did not close: a refusal fails and withholds the marker, while a truncated block parses, stores and commits. "Never completed" is also softened to "not completed for the life of that marker," which is what the in-process marker actually buys: a restart re-reads a bounded tail.
Two statements of my own that were wrong in the same direction as the ones this branch corrects. The collector's remarks said the RDS marker "advances past whatever a successful cycle stored." It advances past everything the cycle consumed, which is more: a slab holding no deadlocks stores nothing and still moves it. Read the narrow way, the sentence invites treating the un-stored remainder as preserved, which is the exact false comfort being removed. FromBlock called a skip on that route "permanent." The resume marker lives in the collector process, so a restart re-reads a bounded tail -- what a skip really costs is the life of that marker, which is what Extract's remarks already say.
|
Reviewed. This is a comments/tests-only change (confirmed via diff — no regex, no SQL, no runtime logic touched in No Lite/Darling parity issue: One inline note on a residual doc inconsistency the PR's own "finish the sweep" framing didn't quite reach — see below. Non-blocking, since the PR text explicitly scopes these out, but worth a look since it's user/LLM-facing text about the exact feature this PR is about. |
|
Follow-up detail on the note above (couldn't inline it — neither file is touched by this diff, so GitHub won't accept a line comment on them):
The PR description explicitly calls these out as "a step removed from this" and leaves them alone since they justify why dedup exists rather than claiming recovery from truncation. That's a reasonable line to draw, but the underlying sentence — "the collector re-reads an overlapping tail every cycle on purpose" as a universal statement — is precisely the false generalization this PR corrects everywhere else it appears. Worth a fast follow-up PR rather than blocking this one. |
…ainer reads it get_pg_deadlocks' tool description and its times_seen note are fed to whatever agent calls the tool. Both said the collector re-reads an overlapping tail so the same report is seen several times and times_seen reports that. On the consume-once route a report is seen once, so times_seen is 1 and stays 1 -- and a consumer told the number is a read-window artifact reads that 1 as "seen once so far, expect more" when it means "this is all there will ever be". The description now splits the two transports and says so in those words. The reader behind it made the same claim three times: its class doc, the times_seen column comment, and DeadlockDetailSql's reason for its DISTINCT ON. The grouping and the DISTINCT ON are still right on both routes; only the reason given was transport-blind. The viewer's Activity-tab read is the fourth, and windowing on occurred_at is likewise correct for a reason that holds on both -- a report is always found some minutes after the fact -- with the re-read tail now named as the pg_read_file route's addition to that rather than as the whole of it. Swept 2686 tracked files for the claim rather than the files pointed at. The plan-capture siblings on get_pg_plans are deliberately left: there the description tells a consumer captures may EXCEED the executions they represent, so on the consume-once route the error runs toward caution rather than toward false reassurance, and the field's own instruction -- get_pg_top_queries.calls is the authority -- holds on both.
Review summaryThis PR is comments/docs-only as described — no SQL, no rungs, no production logic changed outside I also manually traced the two new fixture-based tests ( No Lite/Darling parity gap: One finding posted inline: the MCP-facing |
Review caught the same over-claim a third time, in the place with the least room for it. The tool description and the times_seen note said times_seen "is 1 and stays 1" on RDS and that "no further sightings are coming" -- absolutes, while this branch's own reader doc says a report "normally arrives ONCE" and V104's says the route "repeats less often and for other reasons." The hedged versions are the correct ones: the resume position lives in the collector process, so a restart re-reads a bounded tail, and since #3008 a window whose write did not land is offered again. Either can push times_seen above 1 there. The warning that matters survives -- a low times_seen on that route is the ordinary state and not a partial count, so 1 must not be read as "seen once so far, expect more" -- and the false guarantee around it is gone. An absolute is worst here precisely because these two strings go to a consumer that cannot see the reasoning they came from.
ReviewVerified this is what it claims to be: a comment/doc/description-only correction plus two new pinned tests, no behavioral changes anywhere in the 7 touched files. Correctness of the corrected claims — checked against the actual code rather than taking the PR description's word for it:
Lite/Darling parity — no drift. Security / performance — no input handling, SQL, or network code changed; the SQL-comment edits inside No findings to flag. The |
"There is no setting that suppresses it" is false, and it sat in the same string this branch already corrected twice, aimed at the same consumer. log_error_verbosity = terse drops the DETAIL field, and DETAIL is the whole graph: every wait edge and every participant's SQL. The ERROR: deadlock detected line is still written, so the log looks like it holds deadlocks while the block pattern -- which requires the DETAIL group -- matches nothing. Zero rows from a server that is deadlocking, in the shape of a server that is not. What was true and is kept: a deadlock report needs nothing ENABLED on the target, no preload and no restart, which is the real contrast with auto_explain. Needing nothing enabled is not the same as being unsuppressable, and the four places that said otherwise now say which. #3030's cause is a logging-parameter mismatch nobody checked, and log_error_verbosity and log_min_messages appeared ZERO times across all 2688 tracked files before this. The get_pg_deadlocks description and the viewer panel's doc both enumerate what to check when the result is empty, and both omitted the parameter that turned out to be the answer; the description now names it and points at pg_stat_database's counter as the independent test. Swept case-insensitively by mechanism over the whole tree rather than by phrase: four source sites, all corrected. The CHANGELOG's historical entry is left alone.
|
Reviewed. This is a doc/comment-accuracy PR (plus two new parser tests) with no SQL or behavior changes, as described. No T-SQL is touched (all changed files are in the Darling PostgreSQL/C# side), and there's no Lite counterpart to flag for parity — Lite doesn't do PostgreSQL deadlock collection, so Verified correct:
One issue posted inline: |
"1 for good" in the times_seen column comment contradicted the class doc
four lines above it ("normally arrives ONCE") and the tool description
("not guaranteed to be 1 there either"). It now points at the class
remarks instead of restating a guarantee.
The check that was supposed to catch that did not, and the reason is
worth writing down: it verified the four sites already known to carry a
hedge, which is a positive check. It never enumerated the absolutes that
REMAINED, so a fifth site could not fail it. That is the same defect as
the case-sensitive phrase-list sweep that missed the OVERLAPS spellings,
one level up -- a check over a remembered list rather than over a shape.
Swept by shape instead: 250 added lines across the eight files this
branch touches, merge-base to working tree, case-insensitively, with a
positive and a negative control. It found two more, both introduced by
the first commit and both in the pins' own doc: "the RDS log-API route
is consume-once, so it never is", and "DownloadDBLogFilePortion has
already handed those bytes out and will not again, so this deadlock is
simply gone". The resume marker is in-process, so a restart re-reads a
bounded tail; both now bound the claim to the marker's life.
Six absolutes remain in the added lines and all six are true by
construction rather than by transport behaviour: times_seen is never a
deadlock count because a recurrence carries a different hash, and a
participant count cannot exceed its edge count in a report the server
actually wrote because participants are counted FROM those edges. Those
are arithmetic, not guarantees about a marker.
|
Reviewed. This PR is comments and tests only (confirmed via diff — no non-comment lines changed in Correctness of the claims themselves — traced against the actual implementation rather than taking the doc comments on faith:
New tests (
Lite/Darling parity: no drift. Verified Security / performance: none applicable — no SQL text, input handling, or hot-path logic changed. No findings. |
Closes #3009. (Closing keywords do not fire on a
devmerge, so this is a statement rather than a trigger.)What the comment claimed
PgDeadlockLogParser.Extractjustified skipping an unparseable block with "it will be read whole on the next pass, because the window overlaps." That holds for thepg_read_fileroute and is false for the RDS log-API route, which is consume-once:RdsLogSourcekeeps a resume marker per (instance, file) andDownloadDBLogFilePortionstarts the next call where the last one stopped. There is no overlap and no next pass, so a report straddling a chunk boundary is not completed for the life of that marker. The comment told the next reader that half its callers get a recovery they do not get.What changed
Comments only. No SQL, no rung, no behaviour.
Extract's remarks now separate two claims the old text ran together: truncation at a window edge is ordinary on both transports, and recovery from it happens on one. They also name both loss shapes, because the second is the one a reader would not predict — a chunk ending beforeDETAIL:matches nothing and the report is lost whole, while a chunk ending mid-DETAIL still matches, since the continuation group accepts however many tab-indented lines arrived, and a row lands carrying only the participants, resources and statements that were inside the chunk.The same recovery guarantee appeared in eleven more places, all corrected. Maintainer-facing:
FromBlock's block comment; both places the dedupe hash explained itself by an overlap the managed route does not have;PgDeadlocksCollector's class doc, which named both routes in one sentence and then asserted the overlapping window for the pair; thedeadlock_hashcolumn comment in the definition both routes write through; V103's and V104's rung docs inPgMigrations.cs; the pre-existing hash test's doc;DarlingPgDeadlockReader's class doc, itstimes_seencolumn comment andDeadlockDetailSql's reason for itsDISTINCT ON; and the viewer's Activity-tab read.Consumer-facing, and the reason this went a round further than a comment fix normally would:
get_pg_deadlocks' MCP tool description and thetimes_seennote in its payload are fed to whatever agent calls the tool. Both said the collector re-reads an overlapping tail so the same report is seen several times andtimes_seenreports that. On the consume-once route a report is seen once, sotimes_seenis 1 and stays 1 — and a consumer told the number is a read-window artifact reads that 1 as "seen once so far, expect more" when it means "this is all there will ever be". The error ran toward false reassurance, in the one place a reader cannot see the surrounding argument. Both now split the transports and say so in those words.The grouping, the
DISTINCT ONand theoccurred_atwindowing are all still correct on both routes; only the reasons given were transport-blind, and they are scoped rather than removed.The claim was swept for across 2686 tracked files, by mechanism (
overlap, case-insensitively) rather than by the phrasings already known, which is how the first pass missed the sites spelling itOVERLAPS. Deliberately left:server-tabs.js'stimes_seencolumn label carries no claim; and theget_pg_planssiblings, where the description warns a consumer thatcapturesmay EXCEED the executions it represents — on the consume-once route that error runs toward caution rather than toward false reassurance, and the field's own instruction (get_pg_top_queries.callsis the authority) holds on both transports.Extract's closing paragraph carried a separate, newer staleness: it saidRdsLogSource.ReadNewestAsync"advances and persists its resume marker as a side effect of the fetch, before this parser is reached," so alog_timezonerefusal lost every readable sibling in its window. #3008 moved that commit after the write, andRdsDeadlockIngestornow keeps the parse ahead of the commit specifically so a refusal leaves without it — the next cycle asks for the same window and the siblings survive. That paragraph now says so, and says why the truncation is the case #3008 did not close: a refusal fails and withholds the marker, while a truncated block parses, stores and commits, so the marker advances on the strength of a cycle that succeeded by every signal the ingestor has.PgPlanLogParserand its tests are deliberately left alone. They claim only that a bounded window truncates, which is true of both transports, and never claim the cut block comes back — the shared premise without the false conclusion.PgDeadlocksCollector.ReadAsync's in-loop comment andPgLogTimezoneUnsupportedException's remarks are already transport-scoped and correct. The viewer, reader and MCP-description copies describe why the READ dedupes, which is still necessary, and are a step removed from this.The pins
Two, as distinct tests, because the shapes fail in opposite directions and one test covering the pre-DETAIL cut would pass a fix that left the mid-DETAIL cut in place.
AChunkCutBeforeTheDetailLineLosesTheReportWholeasserts the total loss with the uncut slab beside it, so theAssert.Emptycannot pass because the fixture never parsed.AChunkCutMidDetailStoresAnUnderReportingRow_RatherThanNothingasserts that the fragment PARSES, matches the whole report on timestamp, victim, participant count and lock modes, and under-reports on the columns carrying the evidence: one of the two locked resources, and neither participant's SQL.That second pin also records why no consistency check on the stored row can catch this.
ParticipantCountis counted from the same edgesGraphTextholds, so a fragment lowers both together and they never disagree. What a fragment does leave is a participant count exceeding its edge count, which a whole report — one wait edge per participant — cannot produce.Each pin was proven red independently.
(?:\t[^\n]*\n)*→+ins_deadlockBlockfails the mid-DETAIL pin onAssert.Single; counting participants fromProcess N:headers instead of edges fails it onAssert.Equal, a different assertion. Both left the pre-DETAIL pin green. The pre-DETAIL pin's ownAssert.Emptyis not reachable by a source mutation, and that is a property of the defect rather than a weak test: the fragment contains noDETAIL:and no terminating newline, so the block pattern cannot match however permissive its detail group is made, and handingFromBlockthat fragment directly still returns null because there is no wait edge in it. Its discrimination is proven by moving the cut instead, which fails it on the fixture guard.Measurement, and why the marker withhold is not here
The issue's deciding measurement was not reachable from this work: the PostgreSQL and Aurora targets live in a store it had no connection to, and both stores it could reach hold only SQL Server targets — 85 of 85 servers, with
get_pg_deadlocksansweringnot_collectedas a permanent engine capability gap on each. A SQL Serverget_deadlockscall on the same store returned real rows, so the path and the query form work; there was simply nocollect.pg_deadlocksrow in reach to count.#3030 has since measured the store directly, and it does not give this PR its frequency — it removes the ground the question stood on. That issue found
collect.pg_deadlocksholds zero rows, ever, across 85,549 SUCCESS runs of the RDS route since its 2026-08-30 cutover, while the engines' own counters advanced six times on four targets in the same window: a fleet base rate around 1.2 deadlocks/day against a capture rate of 0%.That is not this defect. Both truncation shapes require a report to reach the parser in order to be cut, and nothing is reaching it. So the honest position is narrower than "the frequency is now known": #3009's truncation rate is not merely unmeasured but currently unmeasurable, because a truncated row cannot be observed in a table with no rows. What these corrections fix is a comment that will mislead the next reader, and a latent loss that starts costing data the day #3030 is fixed — not an active one.
Separately, the measurement as this issue frames it would not have decided anything even with rows to count. Comparing
participant_countagainst the row's own edge list compares a number with the thing it is derived from. The signal that survives in stored data is the cycle arithmetic above, and the pre-DETAIL loss leaves no row at all, so it is only countable against a log window this transport has already consumed.One caveat these pins inherit, and #3030 names it independently: every fixture here is captured from a self-hosted PostgreSQL 17.11 target. Whether the managed engine's
log_line_prefixproduces the same block shape is untested, and #3030 lists that as a candidate cause for the 0% capture.One note for whoever does build the withhold:
RdsLogSource.LogChunkalready carriesMoreAvailable, which separates "the API cut this chunk on its own budget and more is available now" from "this chunk ended at the end of the readable log." That splits the wedge-guard problem where it actually divides — the first is completable immediately, the second is waiting on the server and is the shape that can wedge on a stopped instance. Note that no caller reads it today, in either ingestor, so a withhold would be its first consumer and nothing currently depends on it behaving as documented.The other false claim in the same string
get_pg_deadlocks' description also said PostgreSQL writes a deadlock report "unconditionally - there is no setting that suppresses it". That is false.log_error_verbosity = tersedrops the DETAIL field, and DETAIL is the entire graph — every wait edge and every participant's SQL. TheERROR: deadlock detectedline is still written, so the log looks like it holds deadlocks while the block pattern, which requires the DETAIL group, matches nothing: zero rows from a server that is deadlocking, in the shape of a server that is not.What was true is kept — a deadlock report needs nothing enabled on the target, no preload and no restart, which is the real contrast with
auto_explain. Needing nothing enabled is not the same as being unsuppressable, and the four places that conflated the two now separate them: the parser's and the collector's class docs, the MCP description, and the viewer panel's doc.That last one is why this was worth folding in rather than filing. Both the description and the viewer panel enumerate what to check when the result is empty, and both omitted the parameter that turned out to be the answer —
log_error_verbosityandlog_min_messagesappeared zero times across all 2688 tracked files before this commit. #3030's cause is a logging-parameter mismatch nobody checked, and a false reassurance in agent-facing text is a plausible reason nobody thought to. Same defect class as the recovery guarantee this PR exists to fix: an absolute in consumer-facing text that steers an investigation away from the real cause.Base
origin/devis merged in rather than rebased, so no force-push was needed. dev had moved from114e8cb4etoba7835234across 21 files, none of them this branch's — including #3017's rewrite of the RDS ingestors. That rewrite changesIngestAsync's return type but not its ordering, so this branch's claim that a parse refusal leaves without committing the marker was re-verified against the merged tree and still holds:StoreAsyncruns ahead ofCommitResume, and the tolerantcatchstill wraps only the fetch.Review dispositions
Both findings from the automated review are addressed above: the incomplete sweep is now complete (
PgDeadlocksCollector's class doc and V104's rung doc were the two it named, plus two adjacent instances of the same claim it did not), and the sweep missed them originally because it matched phrases case-sensitively while the collector spells itOVERLAPS.Review then caught the same over-claim a third time, and it was right: the tool description and the
times_seennote asserted that on RDStimes_seen"is 1 and stays 1" and "no further sightings are coming", which is stronger than what this branch's own reader doc ("normally arrives ONCE") and V104 ("repeats less often and for other reasons") say about the same behaviour. The resume position lives in the collector process, so a restart re-reads a bounded tail, and since #3008 a window whose write did not land is offered again — either can pushtimes_seenabove 1 there. Both strings now hedge to match, keeping the warning that matters (a low value on that route is the ordinary state, not a partial count) and dropping the false guarantee. An absolute was worst in exactly those two strings, because they reach a consumer that cannot see the reasoning behind them.The style nit on
System.Text.RegularExpressions.Regexis declined:PgDeadlockLogParserTests.cshas nousing System.Text.RegularExpressions;and its pre-existings_blockCountuses the identical fully-qualified form, so the news_edgeCountmatches the file's own convention rather than departing from it.The missing
CHANGELOG.mdedit is intentional. With several lanes appending to the same[Unreleased]block it is the queue's serialization point, so the entry text ships in this description instead.CHANGELOG entry
Under
[Unreleased]→### Fixed:PgDeadlockLogParser's account of what a truncated deadlock report costs. The parser's remarks claimed a report cut at a read's edge is recovered on the next pass; that is true of thepg_read_fileroute's overlapping window and false of the consume-once RDS log-API route, where the resume marker has already advanced past the fragment. The two loss shapes — a report lost whole, and a report stored under-reporting its participants and statements — are now named and pinned, and the same claim is corrected in the collector's remarks and in the two rung docs that repeated it. (#3009)