Skip to content

Fix two test-side races behind the CISqlServer retries (GH-3821) - #3822

Merged
jeremydmiller merged 1 commit into
mainfrom
gh-3821/sqlserver-test-races
Aug 4, 2026
Merged

Fix two test-side races behind the CISqlServer retries (GH-3821)#3822
jeremydmiller merged 1 commit into
mainfrom
gh-3821/sqlserver-test-races

Conversation

@jeremydmiller

Copy link
Copy Markdown
Member

Closes #3821.

Both retries on CISqlServer in the last green main run (30877953106) were races in the tests,
not product bugs. The handoff flagged these as "the most likely real product bug currently visible
anywhere in CI" — that turned out not to be the case, but they were worth chasing down, and they only
became attributable at all because of the retry-ledger work in #3810.

1. should_reasign_incoming_envelope_to_owner_id — reproduced

PollForScheduledMessagesAsync does two things in one call: it reassigns ownership and flips the row
to Incoming, then hands the envelope straight to the execution pipeline
(SqlServerMessageStore.cs:459). ObjectMother.Envelope() is addressed to
TransportConstants.RepliesUri (local://replies), so with the live runtime the envelope is
enqueued onto a live local queue, executed, and marked Handled — while the test is still on its way
to reading the row back. Sampling the row after the poll:

PROBE t=0ms    count=1 :: status=Incoming owner=1
PROBE t=250ms  count=1 :: status=Handled  owner=1   <- and stays Handled

This also explains the exact failure shape. MarkIncomingEnvelopeAsHandledAsync writes status and
keep_until and leaves owner_id alone, so the OwnerId assertion passes and the Status
assertion fails — which is precisely what CI reported.

Fix: pass a substituted IWolverineRuntime. The poll uses runtime for nothing but
EnqueueDirectlyAsync, so this isolates the database behaviour the test exists to cover. With the
substitute the row is stable across 2s of sampling. The substitute is then asserted against, so the
test now also covers the hand-off, which it never verified before.

Applies to both copies (SqlServerMessageStoreTests and
SqlServerMessageStore_with_IdAndDestination_Identity).

2. sending_recovered_messages_when_sender_starts_up — not reproduced locally

WaitForMessagesToBeProcessed only synchronises on the receiver (trace_doc count and the
receiver's incoming table). The assertion immediately after it is against the sender's outgoing
table, which nothing waited on. Deletion there is asynchronous by construction —
DurableSendingAgent.MarkSuccessfulAsync posts to a RetryBlock rather than awaiting it — so every
send can have succeeded (receiver has all 10 trace docs) while all 10 deletes are still queued. That
is exactly should be 0 but was 10.

Fix: wait for the drain in the loop, and report the last observed counts on timeout instead of a
bare "All messages were not received".

Caveat, stated up front: I could not reproduce this one locally. Instrumenting the loop to
record the outgoing count at the moment the old exit condition first became true gave
outgoingCount=0 on all 6 measured runs — the drain finishes in under 250ms on a quiet machine. The
fix closes a synchronisation gap that exists by construction, but the timing evidence for it is the
CI failure itself, not a local red/green. Reviewers should weigh it on that basis.

The stale // This test "blinks" comment is dropped.

Scope

  • sqlserver_durability_end_to_end — wait for the outbox drain
  • SqlServerMessageStoreTests, SqlServerMessageStore_with_IdAndDestination_Identity — substituted runtime + hand-off assertion
  • marten_durability_end_to_end — same wait-loop gap, fixed and verified
  • RavenDb twin — deliberately left alone. It has the same gap (and already reads the outgoing
    count for its trace line at ravendb_durability_end_to_end.cs:155 without using it in the exit
    condition, so someone hit this before and stopped at instrumentation). There is no ravendb
    service in docker-compose.yml, so I can't run it — and the most expensive lesson in the current
    handoff is shipping an unverified one-line change that reddened 9 jobs. Left as follow-up.

Verification

  • Full SqlServerTests suite: 388 passed, 0 failed, 2 skipped (13m36s)
  • marten_durability_end_to_end: 2 passed
  • Full wolverine.slnx Release build clean before push (per CLAUDE.md)

🤖 Generated with Claude Code

https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m

Both retries on CISqlServer in the last green main run were races in the
tests, not product bugs. They only became attributable because of the
retry-ledger work in GH-3810.

should_reasign_incoming_envelope_to_owner_id asserted a state that
PollForScheduledMessagesAsync deliberately moves past. The poll reassigns
ownership and flips the row to Incoming, then hands the envelope straight
to the execution pipeline via IWolverineRuntime.EnqueueDirectlyAsync.
ObjectMother.Envelope() is addressed to local://replies, so with the live
runtime the envelope is executed and marked Handled within ~250ms --
measured by sampling the row after the poll. That also explains the exact
failure shape: MarkIncomingEnvelopeAsHandledAsync writes status and leaves
owner_id alone, so the OwnerId assertion passed and the Status assertion
failed. Both copies of the test now pass a substituted runtime, which
isolates the database behaviour under test and additionally asserts the
hand-off that was never covered before.

sending_recovered_messages_when_sender_starts_up asserted on the sender's
outgoing table while WaitForMessagesToBeProcessed only synchronised on the
receiver. Outgoing rows are deleted asynchronously --
DurableSendingAgent.MarkSuccessfulAsync posts to a RetryBlock rather than
awaiting it -- so every send can have succeeded while all 10 deletes are
still queued, which is the reported "should be 0 but was 10". The wait loop
now also waits for the sender's outbox to drain and reports the last
observed counts on timeout.

Note: unlike the first race, the second was NOT reproduced locally. The
outgoing count was already 0 at the moment the old exit condition first
became true on all 6 measured runs; the drain finishes in under 250ms on a
quiet machine. The fix closes a synchronisation gap that exists by
construction, but the timing evidence is the CI failure itself.

The same gap in marten_durability_end_to_end is fixed here too. The RavenDb
twin has it as well and is deliberately left alone -- there is no ravendb
service in docker-compose.yml and the exit condition is not runnable
locally.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m
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.

CISqlServer: both retries are test-side races (scheduled-poll status assertion + unsynchronized outbox drain)

1 participant