Skip to content

Commit the RDS resume marker after the write, not inside the fetch (#3008) - #3015

Merged
erikdarlingdata merged 4 commits into
devfrom
fix/rds-marker-commit-after-write
Sep 5, 2026
Merged

erikdarlingdata merged 4 commits into
devfrom
fix/rds-marker-commit-after-write

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 5, 2026 •

Copy link
Copy Markdown
Owner

Closes #3008 only. #3009 stays open — it is a separate defect this does not address; see the last section.

Fixes the ordering defect in #3008: RdsLogSource recorded the RDS resume marker as a side effect of DownloadDBLogFilePortion, before the caller had parsed or stored anything.

The transport is consume-once and the marker is per-process, so any failure between the fetch and a committed COPY consumed a window nobody stored. DownloadDBLogFilePortion does not hand the same bytes out twice, and there is no overlapping re-read to fall back on the way the pg_read_file route has — so every deadlock (or plan) in that window was gone, with no error naming the loss.

The change

ReadNewestAsync returns the candidate marker on the chunk instead of recording it. CommitResume advances it, and each ingestor calls that once, after the rows are durable.

Both ingestors, because both call ReadNewestAsync and the defect was identical in each. Both are covered: RdsDeadlockIngestorTests.cs and RdsPlanIngestorTests.cs are new, the latter added after review pointed out that the plan half had the fix but no test reaching IngestAsync. They hold separate RdsLogSource instances precisely because the marker is consumed per read, so this was never a shared-cursor problem — it was the same bug twice.

Each IngestAsync now reads:

chunk == null            -> 0, nothing was read
StoreAsync(chunk.Text)   -> stores everything the chunk held, or throws
CommitResume(chunk.Resume)

StoreAsync exists to give the commit exactly one predecessor with one rule: every way it can decline to store rows is a legitimate zero that loses nothing (empty text, a slab with no reports in it), and every way it can fail leaves via an exception. So the marker cannot advance over a partial result, and it still advances on a quiet cycle — which matters, because withholding it there would send a quiet target back for the same bounded 10,000-line tail every cycle forever.

Scope of the protection

Not one exception type. Anything thrown between the fetch and the committed write leaves the marker where it was:

  • a parse refusal — now a live path, see the merge note below
  • a COPY that trips importer.Timeout (ServiceCommandDeadlines.CollectionSweepSeconds)
  • a dropped or refused store connection
  • cancellation, including shutdown mid-COPY

That generality is the argument for fixing it at the marker rather than at any one throw. The timezone refusal is what exposed it; it is not what it is about.

What this trades

The transport goes from at-most-once with silent loss to at-least-once: a chunk can be re-stored if the process dies between a committed COPY and the marker moving. That is not a new property of the system. The marker is in memory, so a restart already re-reads a bounded tail, and RdsLogSource's doc comment already records re-reading as the accepted trade — plan rows dedup on (queryid, plan_hash). What changes is that the in-process behaviour now matches the across-restart behaviour that was already chosen, instead of being strictly worse than it.

Worth stating plainly: neither collect.pg_deadlocks nor collect.pg_plan_capture has a unique constraint, so that dedup is read-side, not enforced by the store. A re-store after a mid-commit process death would land duplicate rows. Losing the window is worse, and the pre-existing restart behaviour already accepts this, but it is a real consequence rather than a free one.

One existing test changed semantics

RdsLogSourceTests.FirstReadIsBounded_ThenItResumesFromTheMarker read twice and expected the second read to resume. It now commits between the two reads. Against the fix, its previous form fails with Expected: "MARKER-1", Actual: null — verified by compiling dev's copy of that file against this branch. That is the contract change, deliberate and visible, not an incidental edit.

It is paired with TheMarkerDoesNotAdvanceUntilTheChunkIsCommitted so the two are each other's control: one shows the marker still advances when the caller commits, the other that it does not when the caller doesn't. A fix that broke either would pass the other.

Merge note

origin/dev moved under this branch mid-work: #3001 merged, so PgLogTimezoneUnsupportedException now exists and the parse-throw path this defect was reported through is live rather than latent. #3001 touched RdsDeadlockIngestor.cs and conflicted; resolved keeping both its <exception> doc on IngestAsync and its "not inside the tolerant catch" comment, the latter relocated with the Extract call into StoreAsync and its cross-reference corrected.

ARefusedLogTimezoneDoesNotAdvanceTheMarker then tests the real thing through the real parser and the real exception, rather than a stand-in.

Also post-#3002: RdsLogSource.cs's current copy is the one with named per-branch messages for an omitted AWS response collection. NewestLogFileAsync stays total — no null path was reintroduced, and its ?? throw is untouched.

Verification

Darling.Tests is net10.0-windows and cannot run on macOS, so the real test files were compiled into a throwaway net10.0 xunit v3 host staged outside the repo tree, <Compile Include>-ing the repo paths with <AssemblyName>Darling.Tests</AssemblyName> for InternalsVisibleTo. 31 tests, 0 failed, 0 errors, 0 skipped, 0 not run. Full solution builds with 0 errors.

In CI, Darling.Tests goes from Total: 7521 on dev (406d6446) to Total: 7535 here — +14, matching the 14 tests added, with Failed: 0, Not Run: 0 and none of them in the skip list (that list is entirely live-Postgres tests). The build job ran 495s, so it is not a no-op green.

Red-first, one mutation at a time, restored byte-identical after each (source hash 42c7f89b… before and after both):

Mutation Failures Assertion that moved
Marker recorded inside the fetch (the pre-fix order) 5 Assert.Null(client.Downloads[1].Marker) → "MARKER-1"; and the refused-timezone test's text assertion returns the NEXT window instead of the lost one
CommitResume made a no-op 2 Assert.Equal("MARKER-1", client.Downloads[1].Marker) → null
RdsPlanIngestor commits BEFORE StoreAsync (the shape a shared-helper refactor would produce) 2 the two plan-side guards, while the whole deadlock suite stays green — so the plan tests guard the plan file, not the shared type

The two mutations kill disjoint sets of tests, which is the evidence the "did not advance" guards are not passing against a do-nothing implementation.

Not covered

  • No live store and no live RDS. The store failure is a data source pointed at a closed loopback port, so the COPY genuinely fails at the connection; the AWS side is a fake client. CI's Darling PostgreSQL tests job is the arbiter for the live-store path.
  • The at-least-once duplicate window above is reasoned, not measured.
  • 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 is a sibling defect this does not close, and unlike this one it is active today with no exception required: a deadlock report cut at a chunk boundary is skipped, or matched with a truncated DETAIL block and stored with participants missing. The parse succeeds, so withholding the commit cannot see it. Mechanism, three options and the deciding measurement are in that issue.

Two branches review might expect to be dead, and are not

NewestLogFileAsync became total in #3002, so "RDS listed no PostgreSQL log file" now raises rather than returning a quiet empty chunk. That does not make either early return here unreachable, because they are about different things:

  • chunk is null is the non-RDS host case — RdsEndpoint.TryParse returned null and no AWS call was made. Covered by ANonRdsHostIsSkipped.
  • string.IsNullOrEmpty(text) is an empty download response — DownloadDBLogFilePortion answering a resumed read of a file with nothing appended. That is the ordinary quiet cycle, and it is the path AQuietCycleAdvancesTheMarker depends on.

Neither is the "no log file to open" case, and no null path was reintroduced in NewestLogFileAsync.

This PR touches no classification arm and no timing capture, so it adds no instance of the 0, 0, 0 timing-field pattern in #3011.

CHANGELOG entry text (not committed — for the coordinator to assemble)

### Fixed
- Aurora/RDS PostgreSQL log ingestion no longer loses a window of deadlock reports or `auto_explain` plans when a
  collection cycle fails after fetching it. The RDS resume marker was recorded inside the fetch, before the rows were
  parsed or stored, so on this consume-once transport a parse refusal, a COPY past its deadline, a dropped store
  connection or a cancelled cycle each advanced past text that was never stored, with no error naming the loss. The
  marker is now committed only after the rows are durable, on both the deadlock and plan routes. (#3008)

…3008)

RdsLogSource recorded the marker as a side effect of DownloadDBLogFilePortion, before the caller had parsed or stored anything. The transport is consume-once and the marker is per-process, so any failure between the fetch and a committed COPY consumed a window nobody stored: a parse fault, a COPY past its deadline, a dropped store connection and a cancelled cycle each lost every report in that window with no error naming the loss.

ReadNewestAsync now returns the candidate marker with the chunk, and both ingestors commit it once the rows are durable. The commit sits at one point per ingestor, after a StoreAsync that either stores everything the chunk held or throws, so the marker cannot advance over a partial result.

Applied to the plan route as well as the deadlock route: both call ReadNewestAsync, each holds its own RdsLogSource, and the defect was identical in both.
…after-write

# Conflicts:
#	Darling/PerformanceMonitor.Darling.Service/Targets/RdsDeadlockIngestor.cs
@claude

claude Bot commented Sep 5, 2026

Copy link
Copy Markdown

Review

Scoped, well-targeted fix for the #3008 ordering defect: the resume marker in RdsLogSource now moves via an explicit CommitResume(chunk.Resume) call after the store write succeeds, instead of being recorded as a side effect inside ReadNewestAsync before anything was persisted. The invariant StoreAsync is built around — every decline-to-store path returns a legitimate zero, every failure path throws — is sound, and CommitResume's no-op-on-unset-marker behavior correctly lets both ingestors commit unconditionally on their success path.

Verified by tracing both call sites:

  • RdsDeadlockIngestor.IngestAsync / RdsPlanIngestor.IngestAsync — both now: read → StoreAsync (parse + COPY, throws on any failure) → CommitResume only if StoreAsync returned. A COPY that fails mid-way rolls back via Npgsql's implicit Cancel() on an incomplete binary importer, so there's no partial-write / marker-drift gap.
  • RdsLogSource.CommitResume — correctly keyed by (instance, file), and IsNullOrEmpty guards handle the "read reached end of file, no marker" case as a no-op rather than a crash.
  • Not a Lite/Darling parity issue — this is AWS RDS-log ingestion, which only exists on the Darling (Postgres-capable) side; Lite has no equivalent code path.
  • No T-SQL in this diff, so the collector style rules (table aliasing, OPTION(RECOMPILE), etc.) don't apply here.

One finding posted inline: RdsPlanIngestor got the identical fix but no dedicated regression test — RdsDeadlockIngestorTests.cs (new, 300 lines) thoroughly covers the marker-commit-ordering behavior for the deadlock path (failed write, cancellation, quiet-cycle advance, timezone-refusal), but the only existing plan-ingestor test file only exercises the parser, never IngestAsync/CommitResume. Given the PR's own rationale is "the defect was identical in each," it'd be worth mirroring a subset of that suite for RdsPlanIngestor so a future regression there isn't silent.

RdsPlanIngestor got the identical #3008 fix but had no test reaching IngestAsync: RdsPlanIngestionFromRealLogTests only exercises PgPlanLogParser. The two ingestors hold separate RdsLogSource instances and separate copies of the read-store-commit sequence, so the ordering can regress in one while the other's suite stays green - and folding the two StoreAsync copies into a shared helper is the edit most likely to do it.

Mirrors the deadlock suite's shape rather than transcribing it: failed store write, cancellation, and the quiet-cycle control that a never-firing commit would fail. Uses the real auto_explain capture the plan parser's own suite reads.
@claude

claude Bot commented Sep 5, 2026

Copy link
Copy Markdown

Reviewed the diff (RdsLogSource/RdsDeadlockIngestor/RdsPlanIngestor + the two new test suites and the RdsLogSourceTests changes).

Scope check: this is Darling-only — Lite/ has no RDS log-API ingestion path at all (no RdsLogSource/DownloadDBLogFilePortion/AmazonRDS references anywhere under Lite/), so there's no Lite counterpart to keep in parity here. RdsCpuIngestor (the third RDS-API ingestor) already reads its watermark from the store rather than in-memory, so it doesn't share this bug class and is correctly left untouched.

Correctness:

  • The move of CommitResume to after StoreAsync in both RdsDeadlockIngestor.IngestAsync and RdsPlanIngestor.IngestAsync is consistent between the two files — same order, same reasoning in the comments.
  • StoreAsync's exception boundary is right: the try/catch in IngestAsync wraps only ReadNewestAsync (the AWS fetch), so a parse failure (e.g. PgLogTimezoneUnsupportedException from PgDeadlockLogParser.Extract) or a store/COPY failure both propagate without the marker advancing, and without being mis-swallowed into the RdsLogUnavailableException wrapper meant for fetch failures only. Confirmed the PgLogTimezoneUnsupportedException/RdsLogUnavailableException/PiMetricsUnavailableException classification handlers in DarlingWorker.cs are unaffected and still line up with this ordering.
  • CommitResume's no-op-on-null-marker path is intentional and tested (AQuietCycleAdvancesTheMarker / the plan equivalent) — a caller can commit unconditionally without special-casing "read produced no token."
  • Cancellation path: confirmed the fake AWS client ignores the token (as its comment says), so ACancelledCycleDoesNotAdvanceTheMarker is actually exercising cancellation from the Npgsql store side (OpenConnectionAsync(cancellationToken) on an already-cancelled token), not from the RDS fetch — that's consistent with IngestAsync's structure (the try/catch only covers the fetch, so a cancellation from StoreAsync propagates untouched).
  • The merge-conflict resolution in RdsDeadlockIngestor.cs against Refuse deadlock reports from a non-UTC PostgreSQL log (#2993) #3001 (keeping the <exception> doc tag and relocating the "not inside the tolerant catch" comment into StoreAsync) reads clean — no orphaned comments or duplicated doc tags.
  • Test design is solid: each failure-mode test is paired with a positive control (AQuietCycleAdvancesTheMarker) so a commit that silently never fires wouldn't pass the suite by vacuously satisfying every "did not advance" assertion.

No SQL touched by this PR (T-SQL style / OPTION(RECOMPILE) conventions don't apply here), and nothing here touches credentials, file, or process boundaries beyond what RdsLogSource already did.

Nothing else stood out as a bug or parity risk. Looks good to me.

@erikdarlingdata
erikdarlingdata merged commit 0abd879 into dev Sep 5, 2026
9 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/rds-marker-commit-after-write branch September 5, 2026 13:39
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