Skip to content

fix: make DispatcherModelSpec.A_dispatcher_must_process_messages_one_at_a_time deterministic - #8299

Merged
Aaronontheweb merged 1 commit into
akkadotnet:devfrom
Aaronontheweb:fix/dispatcher-model-spec-one-at-a-time-flaky
Jul 2, 2026
Merged

Aaronontheweb merged 1 commit into
akkadotnet:devfrom
Aaronontheweb:fix/dispatcher-model-spec-one-at-a-time-flaky

Conversation

@Aaronontheweb

Copy link
Copy Markdown
Member

Summary

Makes the intermittently-flaky test A_dispatcher_must_process_messages_one_at_a_time (in the shared ActorModelSpec harness) deterministic. Test-only change — no production code under src/core/Akka/Dispatch/ was modified. The dispatcher/mailbox behavior is correct; the flake was entirely in the test.

The flake

The test held the actor "busy" using a hard-coded, non-dilated Thread.Sleep(1000) in the Wait handler, then asserted the second message's countdown against a Dilated(1.5s) deadline:

a.Tell(new Wait(1000));
a.Tell(new CountDown(oneAtTime));
AssertCountdown(oneAtTime, (int)Dilated(TimeSpan.FromSeconds(1.5)).TotalMilliseconds, "Should process message when allowed");

That leaves only a ~500 ms margin above the fixed 1 s sleep. Under CI ThreadPool starvation the margin is consumed and the legitimate countdown arrives late, producing a false failure. Isolation is never actually violated — the _busy Switch guards it and Restarts stays 0. The 1.5 s wall-clock bound added no correctness value; isolation is enforced independently by the _busy switch plus the trailing AssertRefDefaultZero(..., restarts: 0).

The fix

Deterministic, latch-controlled — mirrors the sibling A_dispatcher_must_process_messages_in_parallel spec's Meet(aStart, aStop) pattern:

  • Replace Wait(1000) with a test-controlled Meet(busyStarted, release) latch so the actor stays busy until the test explicitly releases it — removing the wall-clock race entirely.
  • While the actor is held busy, send CountDown(oneAtTime) and use AssertNoCountdown(..., 500ms) to positively prove the second message is not processed while the actor is busy. This is a stronger "one message at a time" assertion than the old approach, which merely inferred it from a restart that never happens.
  • After releasing the gate, AssertCountdown(oneAtTime, Dilated(3s)) proves the message is processed once the actor is free (matching the 3 s the same test already grants the first message).

Accounting is unchanged

The test still sends exactly three messages (CountDown, Meet, CountDown), so the trailing counts remain correct:

AssertRefDefaultZero(a, registers: 1, msgsReceived: 3, msgsProcessed: 3, dispatcher: dispatcher);

Validation

  • Built Akka.Tests on net10.0 with -warnaserror: 0 warnings, 0 errors.
  • Ran the target test 5x on net10.0: all pass.
  • Ran the full DispatcherModelSpec suite (8 tests, including the sibling parallel spec that shares the harness): all pass.

The `A_dispatcher_must_process_messages_one_at_a_time` test in the shared
`ActorModelSpec` harness was intermittently flaky under CI.

Root cause (test-only race, not a dispatcher bug):
The test held the actor "busy" with a hard-coded, NON-dilated
`Thread.Sleep(1000)` inside the `Wait` handler, then asserted the second
message's countdown against a `Dilated(1.5s)` deadline. That leaves only a
~500ms margin above the fixed 1s sleep. Under ThreadPool starvation on CI the
margin is consumed and the legitimate countdown arrives late, producing a false
failure. Isolation is never actually violated -- the `_busy` Switch guards it and
`Restarts` stays 0.

Fix (deterministic, latch-controlled -- mirrors the sibling
`A_dispatcher_must_process_messages_in_parallel` `Meet(aStart, aStop)` pattern):
- Replace `Wait(1000)` with a test-controlled `Meet(busyStarted, release)` latch
  so the actor stays busy until the test explicitly releases it, removing the
  wall-clock race entirely.
- While the actor is held busy, send `CountDown(oneAtTime)` and use
  `AssertNoCountdown(..., 500ms)` to POSITIVELY prove the second message is not
  processed while busy -- a stronger "one at a time" assertion than inferring it
  from a restart that never happens.
- After releasing the gate, `AssertCountdown(oneAtTime, Dilated(3s))` proves it
  IS processed once free (matching the 3s the same test already grants the first
  message).

Message accounting is unchanged: the test still sends exactly three messages
(CountDown, Meet, CountDown), so the trailing
`AssertRefDefaultZero(registers: 1, msgsReceived: 3, msgsProcessed: 3)` counts
remain correct.

Test-only change. No production code under src/core/Akka/Dispatch/ was modified;
the dispatcher/mailbox behavior is correct.
@Aaronontheweb
Aaronontheweb enabled auto-merge (squash) July 2, 2026 18:05
@Aaronontheweb
Aaronontheweb merged commit ffc1c78 into akkadotnet:dev Jul 2, 2026
11 checks passed
Aaronontheweb added a commit that referenced this pull request Sep 23, 2026
… fixed deadlines (#8609)

* De-flake DispatcherModelSpec: await dispatcher conditions instead of blocking on fixed deadlines

Three tests in `Akka.Tests.Actor.Dispatch.DispatcherModelSpec` failed together on the
Windows unit-test lane of #8601 (ADO build 131736) within ~20s of each other, while Linux
passed:

  A_dispatcher_must_process_messages_in_parallel
    "Failed to count down within 3000 milliseconds. Should process other actors in parallel"
  A_dispatcher_must_dynamically_handle_its_own_lifecycle
    "System.Exception : Await failed"
  A_dispatcher_must_continue_to_process_messages_when_exception_is_thrown
    "Assert.True() Failure", on one of the Assert.True(fN.Wait(...)) lines

#8601 is not implicated. It touches Settings.cs, the ActorSystemImpl scheduler site,
AkkaFeatures.cs, TypeExtensions.cs, an AOT canary app and src/xunitSettings.props -- none of
them on a dispatcher or test-scheduling path, and it does not touch this file (the PR merge
commit's copy of ActorModelSpec.cs is byte-identical to dev's). Its xunitSettings.props
change re-anchors the xunit.runner.json copy from $(SolutionDir) to
$(MSBuildThisFileDirectory); build-system/azure-pipeline.template.yaml compiles with
`dotnet build -c Release` from the repo root -- a solution build, so $(SolutionDir) is set --
and then runs the tests with --no-build, so the file was already reaching bin/ on dev.
Confirmed locally: a project-path build leaves no xunit.runner.json in bin, a
-p:SolutionDir=... build puts it there.

Root cause: all three are the same failure mode. `my-test-dispatcher` runs on
`executor = default-executor`, i.e. the shared .NET ThreadPool
(MessageDispatcherConfigurator.ConfigureExecutor -> ThreadPoolExecutorServiceFactory ->
FullThreadPoolExecutorServiceImpl -> ThreadPool.UnsafeQueueUserWorkItem). Under xUnit v3
with collection parallelism off there is no sync context, so the test body itself runs on a
ThreadPool worker -- the same pool, whose floor is 2 on a 2-vCPU hosted agent. Every wait in
this harness blocked that worker:

* AssertCountdown called CountdownEvent.Wait(ms). In
  A_dispatcher_must_process_messages_in_parallel, once aStart has passed the test thread is
  parked in bParallel.Wait while actor `a` is parked in the Meet handler's WaitFor.Wait() --
  that is the whole pool floor. b.Tell was enqueued from the test thread with
  preferLocal: true, so b's mailbox run sits in the blocked thread's local queue and needs a
  third worker to steal it. CountdownEvent.Wait blocks inside ManualResetEventSlim, which
  does NOT trip the pool's blocking compensation, so the only source of a third thread is
  the starvation heuristic (~1 per 500ms, and slower still when the CPU is saturated).
* Await(until, condition), shared by AssertDispatcher and AssertRef, was a SpinWait hot
  loop. It pinned its own thread AND burned a core, which on 2 vCPUs competes with the very
  workers it waits for and pushes the injection heuristic toward its slow rate.
  AssertDispatcher's deadline was ShutdownTimeout*5 (5s); AssertRef ran seven successive
  Awaits against one shared 1s budget, so the counter that settled last got only the
  leftovers.
* A_dispatcher_must_continue_to_process_messages_when_exception_is_thrown used the
  synchronous EventFilter...Expect, which blocks through Nito's WaitAndUnwrapException, plus
  four Assert.True(fN.Wait(GetTimeoutOrDefault(null))) -- a raw, NON-dilated 3s.

And the cascade: A_dispatcher_must_process_messages_in_parallel signalled aStop only AFTER
the assertion that failed. With the latch never released, actor `a` stayed in the unbounded
meet.WaitFor.Wait() for good, the ActorSystem could not terminate (TestKit's 5s Shutdown cap
and then force-shutdown, matching the 5s dispose in the log), and that ThreadPool worker was
gone for the rest of the test host's life. That is why the other two failed seconds later:
they are victims, not independent flakes.

Fix, in the style of #8299. No timeout was widened, nothing was skipped, and no warning was
suppressed:

* try/finally around the latch-gated sections of A_dispatcher_must_process_messages_in_parallel
  and A_dispatcher_must_process_messages_one_at_a_time, so a failed assertion always releases
  the gate.
* Meet now carries a MaxWait, so its handler's wait is bounded (dilated 10s) and no failing
  test can pin a worker for the life of the process.
* AssertCountdown/AssertNoCountdown became AssertCountdownAsync/AssertNoCountdownAsync, which
  poll latch.IsSet through AwaitConditionNoThrowAsync -- Task.Delay between checks, so the
  thread goes back to the pool. Assertion messages are unchanged.
* Await's SpinWait loop is gone. AssertDispatcherAsync and AssertRefAsync use
  AwaitAssertAsync, which polls with Task.Delay and dilates its own timeout. Same nominal
  bounds as before: ShutdownTimeout*5 and 1s. AssertRefAsync checks all seven counters in one
  polling assertion instead of draining a shared budget serially.
* A_dispatcher_must_dynamically_handle_its_own_lifecycle awaits a.WatchAsync() before
  asserting the dispatcher's stop count. Sys.Stop is fire-and-forget and only the Terminate
  mailbox run needs a pool worker; the dispatcher's idle shutdown then fires on the
  HashedWheelTimer's own thread. Waiting for termination first keeps "the actor never
  stopped" distinguishable from "the dispatcher never shut down".
* A_dispatcher_must_continue_to_process_messages_when_exception_is_thrown awaits
  ExpectAsync(2, async () => ...) and reads each ask with
  (await fN.WaitAsync(RemainingOrDefault)) -- the dilated single-expect default -- instead of
  Task.Wait.
* All 8 tests in ActorModelSpec/DispatcherModelSpec are async Task now, and the last two sync
  TestKit calls (AwaitCondition in A_dispatcher_must_not_double_deregister and in
  AwaitStarted) are awaited.
* Dropped the AwaitLatch/Wait/WaitAck messages and their handlers. Nothing has constructed
  them since #8299 replaced Wait(1000) with Meet, and they held the last unbounded Wait() and
  the last Thread.Sleep calls in the harness -- the remaining route back to this bug.

akka.test.timefactor is 1.0 on CI, so "dilated" is a no-op today. The point of routing every
wait through Dilated/AwaitAssertAsync is that the knob becomes effective for the Windows lane
if we ever need to stretch it.

Test-only change. No production code under src/core/Akka/Dispatch/ was modified; the
dispatcher's behavior is correct.

* ClusterSingletonRestartSpec: name both sources of a repeated HandOverInProgress in the hand-over remark

The <remarks> added by #8600 on AwaitHandOverConfirmationAsync explains the "at least one,
not exactly one" expectation solely through HandOverRetryTimer. That is not the path CI
actually hit, and attributing it to the timer invites someone to tighten the expectation back
to an exact count once the timer looks harmless.

Build 131691's log has ZERO "Retry [n], sending HandOverToMe" lines, and the two
"Hand-over in progress at" lines on the new oldest carry the same millisecond on the same
thread. What happened is a timer-less cross-fire:

  * the new oldest sends its first HandOverToMe on OldestChanged
    (ClusterSingletonManager.cs:916);
  * independently the previous oldest sends TakeOverFromMe (:801), re-sent once a second from
    WasOldest (:1237-1244);
  * the new oldest, still in BecomingOldest, answers that TakeOverFromMe with a SECOND
    HandOverToMe (:1061);
  * the previous oldest, now in HandingOver, answers every HandOverToMe it sees with
    HandOverInProgress (:1304-1308).

So the new oldest logs the line once per HandOverToMe it sent, with no timer involved,
whenever the remote TakeOverFromMe round trip beats the local PoisonPill/Terminated one. The
HandOverRetryTimer is a real second path (armed at :1420, re-sends at :1080-1083, drawing
another HandOverInProgress from the same :1308 case), but the first confirmation cancels it
(:983) -- which is exactly why it leaves no trace in a log that already has the line.

Both paths are designed behavior and both produce N >= 1 lines, so "at least one" remains the
only correct expectation. The remark now names both.

Comment-only change; no test logic touched.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant