Skip to content

RdsLogSource advances the resume marker inside the fetch, so any failure before the write loses that chunk permanently #3008

Closed

Description

@erikdarlingdata

Darling/PerformanceMonitor.Darling.Service/Targets/RdsLogSource.cs records the RDS resume marker as a side effect of the fetch. On the current dev copy that is line 121:

if (!string.IsNullOrEmpty(response.Marker))
{
    _markers[key] = response.Marker;
}

The caller has not seen the chunk yet, let alone stored it. RdsDeadlockIngestor.IngestAsync and RdsPlanIngestor.IngestAsync then parse the text and COPY the rows. If anything between the fetch and a committed COPY fails, the marker has already moved — and on this transport that is permanent. DownloadDBLogFilePortion is consume-once, the marker is per-process and in memory, and the next call resumes past bytes that were never stored. Every readable deadlock (or plan) in that chunk is gone for the life of that marker.

The pg_read_file route does not have this problem. It re-reads an overlapping byte-window tail every cycle, so a cycle that drops a slab gets it again next time. The RDS route has no overlap to fall back on.

What can reach it today

Both ingestors are affected identically. Each holds its own RdsLogSource precisely because the marker is consumed per read, so this is a per-transport bug rather than shared-cursor contention.

Correcting the earlier framing of why this is quiet

An earlier writeup said this was latent because pg_deadlocks RDS log reads were denied fleet-wide by IAM. That is not the case, and it was retracted with store evidence: pg_deadlocks PERMISSIONS rows stop at 2026-08-30 15:09:37, and SUCCESS runs from 15:10:52 onward across all managed targets. The route works and has worked for six days. No IAM denial is current on that fleet.

So the real reason nothing has been lost yet is considerably weaker: no target is known to run a non-UTC log_timezone, so the #3001 throw would not fire even once it lands. Three of the fifty managed targets were sampled directly as UTC, via a shared configuration-file setting — forty-seven were never checked, and nothing in the codebase pins that GUC. Under the IAM framing this was safe until someone deliberately restored a grant. In reality it is safe until one parameter-group change on one cluster: no deliberate act required, and no alarm when it happens.

A latency claim that points at the wrong guardian is worse than no claim, which is why this is recorded here rather than left in a commit message.

Fix direction

Do not persist the marker until the caller has successfully stored the chunk's rows: hand the candidate marker back with the chunk and have the caller commit it after the write. That protects any failure between fetch and durable write — parse, store, cancellation — rather than one exception type, and it needs nothing from #3001.

It also sidesteps the representation problem the asymmetric alternative runs into. DarlingWorker.RunOneAsync classifies a run as either a row count or a thrown status, so "stored 8 rows AND refused some" has no clean representation today. A chunk that is committed whole or re-fetched whole never needs one.

Note that this converts the transport from at-most-once (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: the marker is in memory, so a restart already re-reads a bounded tail, and RdsLogSource's own doc comment records re-reading as the accepted trade. The fix makes the in-process behaviour match the across-restart behaviour that was already chosen.

A sibling defect this does NOT close

Filed separately, because it survives this one closing: same category — the marker outruns durability — different mechanism, and unlike the above it is active now with no exception required.

#3009 — a deadlock report cut at a chunk boundary is skipped or stored with participants missing, and the marker moves past it. The parse succeeds, so withholding the commit cannot see it.

Activity

  1. erikdarlingdata commented on Sep 5, 2026

    @erikdarlingdata
    OwnerAuthor

    Closed by #3015, merged to dev as 0abd8795d1.

    What landed

    RdsLogSource.ReadNewestAsync no longer records the resume marker inside the fetch. It returns the candidate marker on the chunk, and CommitResume advances it only after a StoreAsync that either stores everything the chunk held or throws — one commit point, one invariant.

    The fix is in both callers. ReadNewestAsync has two, not one: RdsPlanIngestor as well as RdsDeadlockIngestor, each with its own RdsLogSource and its own copy of the sequence, and the defect was identical in both.

    Protection covers all three reachable failure modes, each with its own test: a parse refusal, a store-write failure (a COPY past CollectionSweepSeconds, a dropped connection), and cancellation. That generality is the argument for fixing at the marker rather than at any one caller.

    One behaviour a narrower fix would have broken: a quiet cycle must still advance the marker, or a quiet target re-requests the same 10,000-line tail forever. Committing only after a write would have regressed that.

    The cost, stated rather than buried

    At-most-once-with-silent-loss becomes at-least-once. Neither collect.pg_deadlocks nor collect.pg_plan_capture has a unique constraint, so dedup is read-side, and a re-store after a mid-commit process death lands duplicates. The in-memory marker already accepts re-read across a restart; this makes in-process behaviour match it. Losing a window silently was the worse failure.

    Correction to this issue's own framing

    The parse route was described as latent because no target runs a non-UTC log timezone. That was not why. On dev before #3001, PgDeadlockLogParser.Extract could not throw at all — every path is a TryParse or a null return. The route was unreachable, and the paths actually reachable were store-write failure and cancellation. #3001 (3f47ce40a4) added the throw, so the parse route is live now.

    Not verified

    The at-least-once duplicate window is reasoned, not measured. The claim that Npgsql's implicit Cancel() on an incomplete binary importer prevents a partial write was not tested against a real store.

    #3009 is not closed by this and remains open: a deadlock report cut at an RDS chunk boundary is a distinct defect that this fix cannot see, because there the parse succeeds.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions