Skip to content

Fixes #3111 - #3117

Merged
erikdarlingdata merged 4 commits into
devfrom
fix/3111-copy-phase-fault-reporting
Sep 7, 2026
Merged

erikdarlingdata merged 4 commits into
devfrom
fix/3111-copy-phase-fault-reporting

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 7, 2026 •

Copy link
Copy Markdown
Owner

Fixes #3111.

Both follow-ups #3110 left behind, plus the two prose notes that were the reason the issue exists rather than being a closed thought.

1. The three sibling COPY sites now carry the phase axis

RdsPlanIngestor, RdsCpuIngestor and RdsDeadlockIngestor each perform the identical binary COPY into the store and each carried the identical unclosed residual: BeginBinaryImportAsync awaits CopyInResponse under the connection's CommandTimeout while importer.Timeout bounds only the data phase, and both surface as Exception while reading from stream. All three now declare var copyPhase = StoreCopyPhase.Start, transition to Data inside the importer block before the first row, and stamp-and-rethrow-bare on the way out — the same shape and the same reasoning as DarlingCollectorRunner.CopyBatchOnceAsync, which stays the authority the three defer to rather than three copies of its prose.

The pin over them is a scan, not a list: EveryStoreCopyInTheServiceStampsTheCopyPhase discovers the population by finding every file in the service project whose stripped code calls BeginBinaryImportAsync, asserts that set equals the four known sites, and applies the five structural assertions to each with the file name in every failure message. A fifth COPY site reddens it whether or not it is instrumented, which is deliberate — see item 2 for what the set equality is load-bearing for.

The same sweep asserts the converse, which is the half the per-file loop structurally cannot reach: the set of files containing CollectorFaultCopyPhase.Stamp( equals the set containing BeginBinaryImportAsync(. IsProvenStoreWrite's soundness is a biconditional — every COPY stamps, and only a COPY stamps — and a loop over discovered files can say nothing about a file it never visited. Add Stamp( to any target-read path and that fault carries a phase, so the predicate answers true, so the PostgreSQL-target arm excludes it, and a genuine target read is reported as a store write: the same confident-wrong direction IsProvenStoreWrite's remarks argue against, arrived at from the other side. Equality rather than a subset, in one statement, because a COPY site that stopped stamping is also a defect.

That detector matches a qualified call, so the sweep also collects any using static on the axis — which would make Stamp( legal unqualified and blind the scan — and asserts that set empty. An unqualified call from inside CollectorFaultCopyPhase.cs itself is stated as out of scope: that file holds the declaration the pattern is named for, so a text scan cannot tell a call there from the definition, and it is the axis's own home rather than a fault path.

2. A store write no longer receives the PostgreSQL-target read remedy

The target-timeout arm's filter was Target.Engine == PostgreSql && ex is NpgsqlException && Classify(ex) == CommandTimeout. The engine term was standing in for "this fault came from reading the target", and for a store write that proxy is simply false: the store connection is Npgsql whatever the target's engine is, so a COPY timeout satisfies every term and lands there. The arm's remedy is read-specific — "Npgsql cancelled the read mid-stream … the work asked for does not fit the deadline; raising the deadline is the wrong half of that and shrinking the work is the right one."

The filter gains && !CollectorFaultCopyPhase.IsProvenStoreWrite(ex). A recorded phase is written only by a COPY into the store, so it identifies a store write by construction. Those faults fall through to the general arm, which since #3110 already renders the phase into both the app log and the collection_log row — chosen over authoring a second store-side sentence so that one fault reports one way, and because that arm is already where this same fault lands on a SQL Server target. A second sentence would make an identical store fault read differently depending on the monitored target's engine, which the store write has nothing to do with.

StartPhaseLabel and DataPhaseLabel now lead with store-write. Every arm those labels reach also reports faults from reading the target, and a bare "COPY" names the store only to a reader who already knows this product performs no COPY against one.

IsProvenStoreWrite is named for what it can establish: false means "not proven", never "not a store write". The post-COPY dimension flush and commit (#1767) are genuine store writes that read Unknown, and they keep #2997's sentence. That residual is stated in the predicate's own doc rather than papered over, and it is the affordable direction — a store write this predicate cannot prove gets a vaguer message, where the converse hands a confident target-read instruction to something that never touched the target.

The database question, settled by observation

The issue asked for this to be measured rather than argued from the call site, and the report it could not confirm is confirmed. Driving the shipped CopyBatchOnceAsync against a live store with ACCESS EXCLUSIVE held on the COPY target produces a real start-phase timeout, and on it:

  • the fault is NpgsqlException wrapping TimeoutException, classifies CommandTimeout, and did reach the target-read arm;
  • CollectorFaultDatabase.For(fault, runtime.ConnectedDatabase) returns the monitored target's probe database. The store's own database name never appears, because the store-write path stamps no database and For therefore falls back to ServerRuntime.ConnectedDatabase — current_database() on the monitored server, from a different instance entirely.

So the arm named an unrelated database on a different server and gave read-specific advice. The author's guard against naming the wrong database is real but cannot help here: it protects the per-database fan-out case, and there is nothing to fall back to except the target. The fix makes the question moot for the proven population — PostgresTimeoutExplanation is no longer called for it — which is why no change was made to how the database resolves.

Measured before and after on that same real fault:

before: pg_wait_stats on database '<target-db>' hit its CLIENT-SIDE command deadline after 3,000 ms
        — … Npgsql cancelled the read mid-stream … shrinking the work is the right one. …
after:  store-write COPY start phase (awaiting CopyInResponse on the connection's own
        CommandTimeout, no rows sent): Exception while reading from stream

3. IsSafeToReattempt's transport leg is now covered on the real path

The gate is IsTransportFault(fault) && For(fault) == StoreCopyPhase.Start, and the live test that exercised the real path covered only the phase leg. Measured rather than inferred: an unopened connection makes the real BeginBinaryImportAsync raise InvalidOperationException("Connection is not open"), which walks the chain to no socket/stream/timeout link and is not an NpgsqlException either — so it is start-phase, is not a transport fault, and the full gate declines it. Every accepting case in the suite was a hand-stamped, hand-constructed exception, which is the shape where a predicate passes its tests while being wrong about its subject.

ARealStartPhaseTimeoutIsATransportFaultAndTheGateAcceptsIt closes it: the ACCESS EXCLUSIVE blocker makes the backend wait on the lock manager before it can answer CopyInResponse, and the resulting fault is carried end to end into an accepted re-attempt decision — the first test here to make that claim about a fault the runner itself raised. It asserts the premise (NpgsqlException wrapping TimeoutException) as well as the conclusion, so a pass cannot come from the chain walk's NpgsqlException fallback while the fault is really something else. Nothing is written: the lock is taken in a transaction that rolls back and the COPY never completes a row.

Which leg each test covers is now stated in the class summary and asserted in the tests, not left to prose — the existing start-phase test asserts its own decline.

4. The finally justification says the actual reason

CopyFaultAsync recorded that a throwing DisposeAsync in a finally could replace the body's exception. It could not: the helper returns the fault, so by the time a finally would run the catch has already converted it into the return value and there is nothing in flight to replace. The real reason is ordering — what a throwing dispose would replace is the returned exception object, before any caller had read an assertion off it. Leaving disposal to each caller's await using puts it after every assertion, so a dispose that throws can only fail a test whose measurement is already complete.

Incidental, and both found by measurement rather than by reading

AFaultInsideTheRowLoopCarriesData_OnTheRealPath failed on a store being migrated for the first time. PgMigrations sets search_path at database level, which a session picks up only when its physical connection is opened; Npgsql pools, so the COPY connection could be the very one the migrate ran on, carrying the path from before the ALTER. The definition's TargetTable is bare, so the COPY failed 42P01 relation "wait_stats" does not exist — Begin never returned, and the test failed claiming the data phase was unreachable. It survives in a suite where an earlier live class has already migrated, which is the worst version of that. Reproduced on fresh 16.15 and 17.11 stores, fixed by taking the COPY connection from a data source built after the migration, and re-verified fresh on both. Fixed here rather than filed because it is the same method this PR edits and it would have read as this PR's flake.

Two neighbouring pins re-anchored, deliberately. PostgresFaultOutcomeTests.OnlyAnNpgsqlFaultCanEarnTheAuthoredTimeoutNarrative required && ex is NpgsqlException to be adjacent to the Classify term; the new conjunct sits between them, which reddened it without touching anything it asserts. It now forbids an intervening brace instead of counting newlines — both terms must be conjuncts of the same filter, in order, which is the only failure adjacency was ever detecting. RdsLogUnavailableTests.TheIngestorRethrows_RatherThanReturningZeroRowsOnFailure took the first catch of that signature in the file, which is now ambiguous in all three ingestors; it anchors on IngestAsync first. Both were verified still to fire when their subject is removed, and the re-anchoring was shown to discriminate: with a decoy arm above IngestAsync the old form goes red while the new one stays correct.

Deliberately not included

The unbounded start phase itself. #3095 closed completed when #3110 merged, having made the phase distinguishable rather than bounded — so the residual is again recorded only in a comment pointing at a closed issue, which is exactly the recursion TheCopyDeadlineCommentPointsAtTheOpenIssueForTheStartPhase was written to stop. That pin still passes, because it hardcodes #3095 rather than asking whether the issue it names is open. Left untouched: the comment and the pin are #3110's, and whether the fix is a new tracker or a pin that can judge openness is a design call, not a drive-by edit. The three new ingestor comments deliberately point at DarlingCollectorRunner rather than at any issue number, so they add no new instances of it.

A ConnectionFatal store-write fault still forces a TARGET reprobe. A lost store socket during a COPY is an NpgsqlException wrapping IOException, which Classify answers ConnectionFatal, and the general arm's reprobe branch then nulls server.Runtime over a store problem. Pre-existing and unchanged by this PR — a ConnectionFatal store fault already reached that arm — and now fixable with the same axis, but it is a reconnect-behaviour defect rather than a message-attribution one. No reprobe behaviour changes here: the faults this PR moves classify CommandTimeout, which that branch does not match.

The 190 repo-wide xUnit2013 warnings, per the issue.

Verification

Darling.Tests is net10.0-windows and cannot run on macOS, so the pure and source-text tests were compiled into a net10.0 console harness against the real build and executed: StoreCopyPhaseTests 11/11, StoreWriteReattemptTests + PostgresFaultOutcomeTests 57/58 (the one failure is the harness not supplying [InlineData(null)], not a code failure), RdsLogUnavailableTests 16/16. StoreCopyPhaseLivePostgresTests 3/3 against live PostgreSQL 17.11 and 16.15, on fresh stores.

Every new pin was mutation-tested and each fires on exactly the mutation it is for: dropping a stamping arm, moving the Data transition below the row loop, adding a second bare Start, removing the filter term, moving it below Classify, reverting the labels, weakening IsProvenStoreWrite to == Start, adding a fifth COPY site, stamping a phase from a non-COPY file (PostgresTransportFault.cs, which reports the offending file by name), adding a using static on the axis, and a COPY site that keeps its catch arm but stops stamping. The two re-anchored pins were each verified still to fire when their subject is removed. The live transport-leg test goes red with the blocker neutered, reporting that the row loop was reached — so it cannot pass without the condition it induces.

CHANGELOG entry text (not committed — every lane appends to the same [Unreleased] block)

- Extended #3095's COPY phase axis to the three AWS-API store ingestors (`RdsPlanIngestor`,
  `RdsCpuIngestor`, `RdsDeadlockIngestor`), so every binary COPY the service performs reports which
  phase a fault came out of, pinned by a scan asserting both that every COPY site stamps and that no
  other site does.
- A collector store-write timeout on a server whose target is PostgreSQL no longer receives the
  target-read remedy ("shrinking the work") or the monitored target's database name. The COPY phase
  identifies a store write by construction, and those faults now report as a store write in both the
  app log and `collection_log`.

Extend #3095's COPY phase axis to the three AWS-API ingestors, and stop a
PostgreSQL-target read-timeout sentence being applied to a store write.
… fix the data-phase test's pooled search_path dependency
@claude

claude Bot commented Sep 7, 2026

Copy link
Copy Markdown

Review summary

Reviewed the diff (Darling-only: RdsCpuIngestor.cs, RdsDeadlockIngestor.cs, RdsPlanIngestor.cs, CollectorFaultCopyPhase.cs, DarlingWorker.cs, plus tests).

Lite/Darling parity: No gap. Verified that CollectorFaultCopyPhase, the DarlingWorker PostgreSQL-target-timeout arm, and the three Rds*Ingestor classes belong entirely to Darling's central-PostgreSQL-store/binary-COPY architecture. Lite writes to a local DuckDB store and has no binary-COPY ingestion pipeline at all (grep for BeginBinaryImportAsync, CollectorFaultCopyPhase, RdsCpuIngestor/RdsPlanIngestor/RdsDeadlockIngestor under Lite/ returns zero hits). This is consistent with CONTRIBUTING.md's "Two-Store Parity" section, which is about shared-seam interfaces (IAlertStateStore, migrations, etc.) — none of which this PR touches.

Correctness:

  • The three ingestors' new try { ... } catch (Exception ex) when (ex is not OperationCanceledException) { CollectorFaultCopyPhase.Stamp(ex, copyPhase); throw; } wrapper is byte-for-byte structurally identical to DarlingCollectorRunner.CopyBatchOnceAsync's existing shape (copyPhase declared Start before the try, flipped to Data immediately inside the importer block before the first row). No double-stamping risk — IngestAsync's own outer catch (used for the AWS API fetch, e.g. RdsCpuIngestor.cs:159) is a separate code path from WriteAsync's new catch and never wraps it.
  • DarlingWorker's new && !CollectorFaultCopyPhase.IsProvenStoreWrite(ex) filter term correctly routes a store-write COPY timeout on a PostgreSQL target away from the target-read remedy sentence and into the general arm, which already renders the phase into both the log and collection_log. Verified the general arm's ConnectionFatal reconnect branch still won't misfire on this fault (it re-classifies via the same Classify() call, which still returns CommandTimeout, not ConnectionFatal), so there's no reconnect-storm regression.
  • RdsLogUnavailableTests.cs's re-anchoring of the tolerant-catch pin (search from IngestAsync's declaration index) is necessary and correct now that WriteAsync in the same file has an identically-spelled catch signature — confirmed IngestAsync's own catch is declared first in the file, so the fix's IndexOf(..., methodIndex, ...) still finds the right occurrence.
  • Spot-checked the new TheTargetTimeoutArmExcludesAProvenStoreWriteInItsFilter regex window ({0,4000}? between the engine check and the new exclusion term): the actual comment block between them is ~3450 characters, comfortably under the 4000 cap.

Security/Performance: No SQL, network, file, process, or secret handling touched. No T-SQL in this PR (pure C# exception-classification/diagnostics), so the T-SQL style guide doesn't apply. Performance impact is negligible (one local enum variable and a try/catch wrapper per COPY call).

No issues found — LGTM.

IsProvenStoreWrite's soundness is a biconditional and only one direction
was held. Same sweep, plus the using-static route the qualified-call
detector is blind to.
@claude

claude Bot commented Sep 7, 2026

Copy link
Copy Markdown

Reviewed the diff (Darling-only: CollectorFaultCopyPhase.cs, DarlingWorker.cs, the three RDS ingestors, and their tests).

Correctness — checks out. The three ingestors now wrap their COPY in the identical try { copyPhase = Start; using (importer) { copyPhase = Data; ... } } catch (Exception ex) when (ex is not OperationCanceledException) { Stamp; throw; } shape as DarlingCollectorRunner.CopyBatchOnceAsync, byte-for-byte matching what the new EveryStoreCopyInTheServiceStampsTheCopyPhase scan pins. The Start→Data transition sits inside the importer block before the first row in all three, so a re-attempt via StoreWriteReattempt still can't be authorized on a fault that may have already sent rows.

The new DarlingWorker exclusion (&& !CollectorFaultCopyPhase.IsProvenStoreWrite(ex)) is correctly placed above the Classify(...)== CommandTimeout call in the PostgreSQL-target timeout arm's filter (confirmed at DarlingWorker.cs:6547-6574), so a store-write COPY timeout on a PostgreSQL target now falls through to the general catch-all instead of getting the read-specific "shrinking the work" remedy. IsProvenStoreWrite's asymmetry (false = "not proven," never "not a store write") is documented and matches how it's used — only the general arm's message changes for the proven population; the unstamped post-COPY flush/commit (#1767) is left alone as before.

Lite/Darling parity — no drift. RdsPlanIngestor/RdsCpuIngestor/RdsDeadlockIngestor and this whole COPY-phase/fault-classification mechanism are Darling-only (RDS/CloudWatch API ingestion has no Lite counterpart), confirmed via grep — nothing to mirror on the Lite side.

Security/performance — no concerns. No new input handling, no secrets, no new SQL surface (COPY commands are unchanged, still driven by existing collector definitions). The try/catch wrapping adds no measurable overhead on the collection path.

The new EveryStoreCopyInTheServiceStampsTheCopyPhase scan-based pin (rather than a fixed file list) and the live start-phase-timeout test (ARealStartPhaseTimeoutIsATransportFaultAndTheGateAcceptsIt, gated on DARLING_TEST_PG) are a solid way to keep this from regressing silently if a fifth COPY site shows up later.

No issues found.

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