Repository navigation
A deadlock report cut at an RDS chunk boundary is lost or stored incomplete — the parser's "the window overlaps" is false for the consume-once route #3009
Description
PgDeadlockLogParser.Extract's doc comment justifies skipping a block that will not parse like this:
both transports read a bounded window, so a report cut in half at the edge is an ordinary consequence of not reading the whole file rather than a fault worth surfacing every cycle. It will be read whole on the next pass, because the window overlaps.
That is true of the pg_read_file route and false of the RDS/Aurora route. pg_read_file re-reads an overlapping byte-window tail every cycle, so the next pass genuinely does see the whole report. DownloadDBLogFilePortion is consume-once: RdsLogSource keeps a per-(instance, file) resume marker and the next call starts where the last one stopped. There is no overlap and no next pass. A report cut at a chunk edge is never completed.
Mechanism
DownloadDBLogFilePortion cuts on its own line/size budget, not on report boundaries. A PostgreSQL deadlock report is multi-line — the ERROR: deadlock detected line, then a DETAIL: block plus every tab-indented continuation, which can include multi-line SQL. So a chunk boundary can land inside one, and there are two outcomes, both bad:
- The chunk ends before
DETAIL:.s_deadlockBlockrequires the DETAIL group, so there is no match and the whole report is skipped. Silent total loss of that deadlock. - The chunk ends mid-DETAIL.
(?:\t[^\n]*\n)*matches whatever continuation lines are present, so the block does match — with a truncated DETAIL.FromBlockfinds at least one wait edge and returns a report with participants and statements missing. That is worse than absence: a stored row that under-reports the deadlock, indistinguishable from a genuinely smaller one.
In both cases RdsLogSource has already moved the marker past the fragment, so the remainder is never fetched again.
Why the marker-ordering fix does not close it
Withholding the resume marker until the rows are durable does not help here, because nothing fails. The parse succeeds — it just returns fewer reports, or less complete ones, than the chunk contained. The write succeeds. The commit is legitimate by every signal the ingestor has. The loss is invisible at every layer.
Options, none free
- Have the parser report that the chunk's tail held an incomplete block, and withhold the marker until it is whole. Needs a wedge guard: a tail that stays truncated (log rotation, a stopped instance, a report that is genuinely the last thing in the file) must not pin the marker forever. The existing per-file marker key already resets on rotation, which covers part of it. This is the only option that actually recovers the data.
- Overlap the reads the way the file route does. Not available: the RDS marker is an opaque service token, so a byte-offset rewind cannot be constructed from it.
- Accept it and document the transport's truncation loss, so the doc comment stops claiming an overlap this route does not have. Cheapest, and strictly better than the current state where the comment asserts something false for half its callers.
Option 1 changes a parser shared with the pg_read_file route, where truncation genuinely is harmless, so it deserves its own decision rather than being folded into the marker fix.
The measurement that should decide it
How often a chunk boundary lands inside a deadlock report on a real target. The store can answer it: compare participant_count and the graph_text of collect.pg_deadlocks rows arriving via the RDS route against the reports actually present in the corresponding log window, and count rows whose edge list is inconsistent with their participant count. If that is rare, option 3 is enough; if it is not, option 1 is worth its wedge guard.
At minimum, option 3 should happen regardless — the doc comment currently tells the next reader that a truncated report will be recovered, and on this transport it will not be.
Activity
Say which transport recovers a truncated deadlock report, and pin wha…
erikdarlingdata commentedon Sep 5, 2026
Closed by #3028.
Part A — the false recovery guarantee was in 12 places, not one
This issue named
Extract's comment. A sweep by mechanism (grep -i overlap) over 2,686 tracked files found 12 instances across 7 files. All corrected.The text now states, per transport: the
pg_read_fileroute re-reads an overlapping byte-window tail every cycle, so a report cut at one read's edge arrives whole in the next; the RDS log-API route is consume-once, holds a resume marker per (instance, file), and a straddling report is not completed for the life of that marker.Both loss shapes are named, and the detectable signal is recorded: a participant count exceeding its edge count. Not the comparison this issue proposed — see below.
A correction to this issue's own specified measurement
The measurement asked for here cannot work: it compares
participant_countagainst the edge listparticipant_countis derived from. A fragment lowers both together and they never disagree.What survives in stored data is the reverse inequality — a participant count greater than the edge count, which a whole report cannot produce, since a cycle on N nodes has N edges.
Part B — the frequency is not merely unmeasured, it is currently unmeasurable
Both reachable stores hold 85 of 85 SQL Server 2022 targets, and
get_pg_deadlocksreturnsnot_collectedas a permanent engine capability gap — positive-controlled byget_deadlockson the same store returning 24 real rows.aws ssm send-commandwas classifier-blocked, closing the second route.More importantly, #3030 answers a different question than this one. It measured that the RDS route has stored zero rows ever across 85,549 SUCCESS runs while the engines counted six deadlocks post-cutover. But both truncation shapes require a report to reach the parser, and #3030 proves none does — its cause is a
log_line_prefixmismatch that makes the block regex match nothing.So a truncated row cannot be observed in a table with no rows. This issue's rate becomes measurable the day #3030's fix lands, and that fix is now dispatched with the fixture gap as part of its scope.
That also settles this PR's value honestly: a corrected comment plus a latent loss that begins costing data when #3030 is fixed — not an active loss today.
Both truncation cases pinned, as distinct tests
(?:\t[^\n]*\n)*→+fails the mid-DETAIL pin onAssert.Single; counting participants from statement headers fails it onAssert.Equal. Both leave the pre-DETAIL pin green.The pre-DETAIL pin's
Assert.Emptyis unreachable by any source mutation — proven with a probe and two independent gates: noDETAIL:and no terminating newline, and no wait edge, soFromBlockreturns null even when handed the fragment directly. Its discrimination is therefore proven by moving the cut rather than by mutation. That is an honest account of a pin that cannot be mutation-killed, stated rather than glossed.Part C — not implemented, and a note for whoever builds it
No frequency existed to weigh a wedge guard against, and a marker withhold that pins forever on a permanently-truncated tail is worse than the loss it prevents.
LogChunk.MoreAvailablesplits the guard problem correctly — "cut on the API's budget, more available now" versus "ended at the readable end of the log" — but no caller reads it today, so a withhold would be its first consumer.A claim #3008 had already falsified
ExtractsaidReadNewestAsync"advances and persists its resume marker as a side effect of the fetch." #3008 moved that commit after the write, so a timezone refusal now leaves without committing. Post-#3008 the refusal costs the same on both transports, and the asymmetry has moved to truncation — this issue's thesis, arrived at from the other end.The record worth keeping: six over-claims introduced by the corrections
Fixing a false absolute produced six new false absolutes across this PR's six heads — "never completed", "is permanent", "times_seen is 1 and stays 1", "no further sightings are coming", "1 for good", and two in the pins' own doc claiming the deadlock is "simply gone". Every one contradicted by the same fact: the resume marker is in-process, so a restart re-reads a bounded tail.
Two were caught on re-read, two by review, and two by a shape sweep that neither review nor the lane's own parity check had found across four commits.
Why the parity check failed is the transferable part: every assertion in it was positive. It grepped for the hedge phrases just written and confirmed each appeared where expected — so nothing in it could fail on a site nobody had thought of, because it never enumerated what remained. A check over a remembered list of sites cannot find an unremembered site, exactly as an earlier sweep over a remembered list of phrases missed the
OVERLAPSspellings.Six absolutes deliberately remain, on a principled line: an absolute about how a number is computed is arithmetic and fine (a participant count cannot exceed its edge count;
times_seenis never a count of deadlocks, since a recurrence carries a different hash). An absolute about what a transport will do is what kept being wrong.And the right test of a hedge, applied by review on the final head: it re-derived the claim rather than accepting it, confirmed
RdsLogSource._markersis an in-memoryDictionaryrather than persisted, and called the phrasing "accurate, not just softer-sounding." Whether a hedge is true is the question; whether it is softer is not.Not verified
Whether a seventh absolute exists in a wording the pattern list did not name — the claim is "clean against eleven named shapes over 250 added lines with positive and negative controls," not "contains no absolutes."
log_min_messages' exact behaviour on a deadlock ERROR is named in the corrected description as a second thing to check but was not itself verified; the verified mechanism islog_error_verbosity = tersedropping the DETAIL graph. Every fixture here is self-hosted 17.11 — the managed-format fixture is #3030's fix lane's job, not this one's.