Log the cause when a capture recovery settlement fails - #2058
Merged
Merged
Conversation
AgentRunLogCaptureRecoveryService.RecoverClaimAsync counted any exception from SettleAsync as a lost lease and logged nothing. A guard RAISE, a unique violation, a dropped connection and a settlement timeout all looked the same: the claim sat leased and idle until its lease expired, with no trace of why. That is how the retry-clause refusal fixed by 0240 passed for an unreproducible flake. The catch now logs a warning naming the run, the intent, and the state and last_error_code the settlement was writing. When a PostgresException is in the exception chain it adds that exception's SqlState and MessageText. For any other cause, such as a settlement cancelled at the end of its budget, both are null and the attached exception carries the cause. The warning also says the claim waits out its lease before a later wave re-claims it. The state and code named are the ones the guard judged. Before it writes, SettleAsync can replace the outcome it observed with Superseded or recovery-exhausted, so it records the outcome it is writing in a SettlementAttempt that the catch reads. The catch no longer names the outcome it passed in. The outcome is unchanged. A settlement that raises is presumed unwritten, so its claim keeps this wave's owner and lease whatever the cause, and no typed outcome other than a lost lease exists for that. Retrying inside the wave would only repeat a deterministic refusal. The service now takes an ILogger from the container.
ppXD
added a commit
that referenced
this pull request
Oct 4, 2026
After #2058, AgentRunLogCaptureRecoveryService still had three paths that dropped the cause of a claim it could not settle. RecoverClaimAsync turned any exception from the recovery step into a typed retry, recovery-operation-exception, and discarded the exception. A deterministic fault then repeats on every retry until the intent is exhausted into ExternalStateIndeterminate, and nothing says why. It is now logged as a warning in the shape #2058 uses: run, intent, the exception, and the SQLSTATE and message text of any PostgresException in its chain, plus the retry the step's outcome became. The line is written before the settlement runs, so it names that outcome without promising it: on the last allowed attempt the settlement exhausts the intent instead, a changed worker fence supersedes it, and a lost lease writes nothing, and the line says so rather than "recovered again once the retry falls due". SettleAsync returned a lost lease with no log line when its lease re-check failed and when its write matched no row (DbUpdateConcurrencyException). Each exit now logs a warning naming the run, the intent, the outcome it discarded, and why: lease-expired, reclaimed, row-version-changed, or claim-row-missing (which the ON DELETE RESTRICT key and the DELETE guard make unreachable today). The concurrency exit names the write it discarded, which the settlement may already have replaced with an exhausted or superseded outcome, not the outcome it observed. The level is Warning, not Information: the constructor makes a lease outlive both bounded steps of a claim, so a live worker loses one only when a step overruns the bound its cancellation sets, the process stalls, or the row changes under the settlement's own FOR UPDATE lock. None of that is routine. Each loss costs a re-claim and another recovery attempt, and for a legacy intent that attempt counts toward exhaustion. It is not an Error either, because the fence keeps the loss safe. Nothing read the LostLease tally, because the recurring job discards the reconcile summary. ReconcileAsync now logs the summary at Information when its wave claimed anything, as AgentRunReconcilerService and AgentRunSpoolReaper log theirs, so the job and its handler stay thin dispatchers. Every path still returns the same settlement or retry as before.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
AgentRunLogCaptureRecoveryService.RecoverClaimAsyncturned any exception fromSettleAsyncinto a lost lease and logged nothing. A guard RAISE (P0001), a unique violation, a dropped connection and a settlement timeout all left the claim leased and idle until its lease expired, with no trace of why. That is why the retry-clause refusal fixed in Check capture retries against the settling transaction's start #2057 looked like an unreproducible flake.last_error_codethe settlement was writing. When aPostgresExceptionis in the exception chain, it also logs that exception'sSqlStateandMessageText. For any other cause both are null, and the attached exception carries the cause. The warning says the claim waits out its lease before a later wave re-claims it. Before it writes,SettleAsynccan replace the observed outcome withSupersededorrecovery-exhausted, so it records the outcome it writes in aSettlementAttempt. The log therefore names the write the guard actually judged.DbUpdateConcurrencyExceptionexits inSettleAsyncstay unlogged. They are real lease losses, or impossible under the row lock. TheRecoverAsynccatch still drops its cause, but it settles as a typedrecovery-operation-exceptionretry.Test plan
A_settlement_the_database_refuses_is_logged_with_the_write_it_refused_and_still_waits_out_its_lease, a Theory with 2 rows.RefusedCaptureSettlementInterceptormakes the guard refuse only the owned intent's settlement write, retry or terminal, and a due neighbour sits ahead of that intent. The test asserts:RunIdsetOutcome/OutcomeCodeof the refused write:SourceFinalized/complete-backend-unavailable, orExternalStateIndeterminate/recovery-exhaustedwithMaxAttempts = 1SqlStateP0001 and aMessageTextnaming the intentLostLease >= 1and the claim still leasedA_settlement_that_outlives_its_budget_is_logged_without_a_database_cause_and_still_waits_out_its_lease:SlowCaptureSettlementInterceptorholds the owned run's settlement read until the settlement budget cancels it. The test assertsSqlStateandMessageTextnull, anOperationCanceledException, and the same lost-lease outcome.refusal!.SqlState: the budget test, with aNullReferenceExceptionescapingReconcileAsyncattempt.Outcome = settled: the exhausted rowAgentRunLog*+*LogCapture*family, 112 of 112. The recovery flow class 5 runs in a row, 24 of 24 each time. Each new test alone in a cold process, 3 times each.dotnet build CodeSpace.sln: 0 errors.Depends on #2057.