Skip to content

GH-3779: a dev-scale reproduction of slow agent starts, and the first flaky-tag burn-down (GH-3763) - #3780

Merged
jeremydmiller merged 4 commits into
mainfrom
gh-3779/slow-agent-start-harness
Aug 2, 2026
Merged

GH-3779: a dev-scale reproduction of slow agent starts, and the first flaky-tag burn-down (GH-3763)#3780
jeremydmiller merged 4 commits into
mainfrom
gh-3779/slow-agent-start-harness

Conversation

@jeremydmiller

@jeremydmiller jeremydmiller commented Aug 2, 2026

Copy link
Copy Markdown
Member

Two independent pieces of testing work, both off the open testing/CI issues, plus a leftover from #3725.

GH-3779 — a fast, deterministic reproduction of slow agent starts

Every defect in the GH-3753 chain — #3748, #3749, #3750, #594, #598 — takes a slow agent start as its precondition, and FakeAgent.StartAsync returned Task.CompletedTask, which is exactly the assumption the whole chain violates.

First, a correction to the issue's premise. src/Testing/SlowTests/Agents/ already contains a real reproduction — agent_assignment_at_scale, agent_reassignment_at_scale, slow_starts_outrun_reply_windows — built during the #3748/#3749/#3750 work, with real hosts, real delays, telemetry and a universe that grows mid-test. Those are the thorough version and they already assert the monotonicity the issue asks for.

The gap is different from what #3779 describes:

  1. SlowTests runs in no CI workflow at all. Zero jobs in tests.yml, no Nuke target. Three well-built regression tests for this chain run nowhere.
  2. They take minutes apiece and are wall-clock-sensitive, so they can't be the guard on a normal commit.

This PR adds the fast tier underneath them — 0.5s, deterministic, inside a job that already runs on every commit.

The harness seams the issue asks for

  • FakeAgent gets a settable StartDelay/StopDelay and counts entries into StartAsync, so a start that is merely slow can be told apart from one the leader has re-driven.
  • FakeAgentFamily gets an agent count and a StartDelayPolicy, so a long tail can be simulated rather than a uniform cost. It is the tail that does the damage — a uniformly slow family converges late but converges.

The simulation

slow_agent_start_convergence drives the real NodeAgentController.EvaluateAssignmentsAsync round after round against a simulated multi-node cluster (5 nodes / 603 agents) and asserts what the field reported losing:

Assertion Field shape it guards
every agent converges the wave that never finished
no agent started on two nodes at once GH-3698's re-decide-from-scratch
no node starved while another holds everything the observed 799 / 0 / 0 / 0 / 1
a first placement wave emits zero stops and zero reassignments the churn that made convergence a livelock
a start slower than the ledger TTL is still held by the outstanding-dispatch probe GH-3698, with the TTL squeezed to nothing
a partially-started chunk's remainder still converges GH-3750

Two design points worth naming:

Time is measured in evaluation rounds, not milliseconds. The field distribution is p50 27s / p95 82s / a 215s tail against a ~5s health-check cadence; a wall-clock version would take hours and would trade a deterministic assertion for a timing race. Everything is seeded — a failure reproduces.

An agent becomes running one round before it becomes visible to the leader. A node persists its assignment row only after the agent is up, and the leader reads it on a later snapshot — that window is what GH-3750 is about, and a simulation that closes it instantly cannot reproduce the field's falling assigned-agent count.

These assertions were checked against mutated product code

Not just "they pass". Two mutations were applied and reverted:

Every assertion in the final file fails under at least one. The one that didn't — the monotonic running-count check — is documented as strictly implied by the zero-churn assertion against a stable node set, and now rides inside that test rather than standing as a test that cannot fail.

GH-3763 — first entry off the Category=Flaky ledger

batch_processing_with_kafka.end_to_end was tagged flaky. It is not flaky; it failed on every run, in isolation, exactly as #3763 predicted the tag would be hiding.

The cause is application-assembly resolution, not batching. The sample is booted by Wolverine.Kafka.Tests through AlbaHost.For<Program>, and Wolverine resolved the application assembly to the test assembly:

APP=Wolverine.Kafka.Tests | DISCOVERY=Wolverine.RuntimeCompilation,Wolverine.Kafka.Tests

So discovery never scanned BatchMessaging, TestMessagesHandler was never found, and BatchMessagesOf<TestMessage>() had no TestMessage[] chain to bind to. The sample even carried a comment recording the symptom as expected behaviour. This is the GH-3521 class of problem — #3777 stopped the runner assembly being adopted, which is a different assembly from this one.

Fixed by pinning opts.ApplicationAssembly in the sample, which is the repo's own convention for a sample driven by an Alba test from another assembly (WolverineWebApi/Program.cs:192 does exactly this).

That exposed a second, real problem: the test asserted a single batch of two. BatchingOptions triggers on a full batch or on TriggerTime (250ms), so whether two messages published back-to-back land in one batch or two depends on how the Kafka consumer slices its polls — asserting the grouping asserts a race. It now asserts what the contract promises: every published message arrived at the handler batched.

Untagged; green 5/5 locally.

Second pass: the RabbitMQ block

Nine Rabbit classes carried the tag. Measured against a fresh broker, dotnet test directly so nothing was retried:

Seven are stale tags — untagged. force_restart_listener_3232, RabbitMqBrokerHealthProbe_tests, sending_raw_messages, cluster_endpoints, endpoint_health_connection_state_3231, both send_by_topics classes, Bug_189: 5 consecutive runs, 41 tests, zero failures.

Two are real, and neither is "flaky". Both keep the tag, now with the measurements in a comment beside it:

end_to_end was very nearly untagged with the rest, because it was not in the filter used for the repeat runs — that would have put a guaranteed red into CIRabbitMQ. Verify each class you untag by name.

Ledger: 53 → 44. (The RabbitMQ commit message says "53 -> 45"; 44 is correct — send_by_topics carries two tags in one file. The code is right, only that one number in the message is off, and the branch ruleset blocks the force-push an amend would need.)

GH-3725 tail — a comment that now says the opposite of the truth

#3725 deleted <XUnitCancellationTokenEnforced> from every project along with the Directory.Build.targets block that read it, but left <!-- GH-3702: xUnit1051 reinstated for this project --> behind in 71 project files. xUnit1051 is not "reinstated for this project" any more — it is enforced for every project by default, which was the point. Pure deletions; wolverine.slnx builds clean in Release with 0 warnings.

Deliberately NOT in this PR: wiring SlowTests into CI

That was the obvious next step for #3779, and it is blocked — but not by the tests. SlowTests.Agents passes on main; what it cannot do is finish.

agent_reassignment_at_scale.a_version_bump_deploy_converges_and_never_marches_backwards runs all of its assertions green and then hangs forever in teardown, so dotnet test never reports and the process has to be killed. Reproduced 4/4, including on a completely idle machine.

The controlled pair that isolates it — the only difference is a 20s bound on the teardown stop:

DisposeAsync Result
await host.StopAsync() (as committed) hangs indefinitely; the run never reports
await host.StopAsync().WaitAsync(20.Seconds()) passed, 2m18s

So the assertions are fine, and a host shutdown is what wedges. Details worth having:

  • The host left standing is node 1 — the first host created, therefore the last one DisposeAsync stops after _hosts.Reverse(), and the leader. The other two stop cleanly (the assignment table drains 478 → 322 → 192 and then stops moving).
  • It is not the simulated slow stop: DisposeAsync sets _telemetry.StopDelay = TimeSpan.Zero before stopping anything.
  • dotnet-stack report on the wedged process shows every managed thread parked — thread-pool workers idle, main thread blocked in the xUnit entry point, no CPU burn. That rules out a spin or a lock convoy and points at an await that is never completed.
  • The node's health_check row stops updating ~2 minutes in and the row is never deleted, consistent with the runtime going quiet mid-shutdown.

A product-side shutdown hang in a Balanced-mode host holding a large number of agents, unrelated to anything here — SlowTests uses its own SlowStartAgentFamily and never touches FakeAgent. Written up separately rather than papered over, because bounding the teardown inside the test would hide a real hang.

Addresses #3779; deliberately does not close it. Two things it asks for are still outstanding and both sit behind the hang above:

  • SlowTests wired into a CI job, so the existing scale harness actually runs somewhere;
  • the virtual clock, which only pays for itself once those tests are in CI and their wall clock matters.

🤖 Generated with Claude Code

https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA

jeremydmiller and others added 3 commits August 2, 2026 09:16
Every defect in the GH-3753 chain -- GH-3748, GH-3749, GH-3750, #594,
#598 -- takes a SLOW AGENT START as its precondition, and
`FakeAgent.StartAsync` returned `Task.CompletedTask`, which is precisely the
assumption the whole chain violates.

SlowTests/Agents already reproduces this against real hosts and real delays, and
those three tests are the thorough version. They also run in NO CI workflow and
take minutes apiece, so nothing guards the leader's assignment logic on a normal
commit. This adds the fast tier underneath them.

Harness seams, as the issue asks for:

- `FakeAgent` takes a settable `StartDelay`/`StopDelay` and counts entries into
  `StartAsync`, so a start that is merely slow can be told apart from one the
  leader has re-driven.
- `FakeAgentFamily` takes an agent count (the twelve hard-coded `Names` are fine
  for asserting the shape of a distribution, not for the ~6,500-agent shape that
  actually breaks) and a `StartDelayPolicy`, so a long TAIL can be simulated
  rather than a uniform cost. It is the tail that does the damage: a uniformly
  slow family converges late but converges.

`slow_agent_start_convergence` then drives the real
`NodeAgentController.EvaluateAssignmentsAsync` round after round against a
simulated multi-node cluster and asserts the properties the field reported
losing: every agent converges, no agent is ever started on two nodes at once, no
node is starved while another holds everything, a first placement wave emits zero
stops and zero reassignments, a start slower than the ledger TTL is still held by
the outstanding-dispatch probe, and a partially-started chunk's remainder still
converges.

Two things worth naming about the simulation:

Time is measured in evaluation ROUNDS, not milliseconds. The field distribution
is p50 27s / p95 82s / a 215s tail against a ~5s health-check cadence, so a
wall-clock version would take hours and would trade a deterministic assertion for
a timing race. Everything is seeded; a failure reproduces.

An agent becomes RUNNING one round before it becomes VISIBLE to the leader. A
node persists its assignment row only after the agent is up and the leader reads
that row on a later snapshot, so there is a window in which an agent is genuinely
running and looks completely unplaced -- that window is what GH-3750 is about,
and a simulation that closes it instantly cannot reproduce the field's falling
assigned-agent count.

Every assertion was checked against two mutations of the product code (the
pending-assignment ledger never projected onto the grid; the pending placement
set but not held) and each fails under at least one. The monotonic running-count
check is the exception -- no mutation makes it fail, because against a stable
node set it is strictly implied by the zero-churn assertion -- so it rides along
inside that test, documented as the operator-visible restatement, rather than
standing as a test that cannot fail.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA
First entry off the `Category=Flaky` ledger, and it is the shape #3763 predicted:
the tag was hiding a deterministic failure, not a flake. `end_to_end` failed on
every run, in isolation, with

    This Wolverine application has a configuration for batching messages of type
    TestMessage, but there is no known handler for TestMessage[]

The cause is application-assembly resolution, not batching. `BatchMessaging` is
booted by `Wolverine.Kafka.Tests` through `AlbaHost.For<Program>`, and Wolverine
resolved the application assembly to the *test* assembly:

    APP=Wolverine.Kafka.Tests | DISCOVERY=Wolverine.RuntimeCompilation,Wolverine.Kafka.Tests

So handler discovery never scanned `BatchMessaging` at all, `TestMessagesHandler`
was never found, and `BatchMessagesOf<TestMessage>()` had no `TestMessage[]`
chain to bind to. The sample even carried a comment recording the symptom as
expected behaviour. This is the GH-3521 class of problem; GH-3776/#3777 stopped
the *runner* assembly being adopted, which is a different assembly from this one.

Pinned `opts.ApplicationAssembly` in the sample, which is the repo's own
convention for a sample app driven by an Alba test from another assembly --
`WolverineWebApi/Program.cs:192` does exactly this.

That exposed a second, real problem underneath: the test asserted a SINGLE batch
of two. `BatchingOptions` triggers on a full batch OR on `TriggerTime` (250ms),
so whether two messages published back-to-back land in one batch or two depends
on how the Kafka consumer slices its polls -- asserting the grouping asserts a
race. It now asserts what the contract actually promises: every published message
arrived at the handler in batched form.

Untagged, and green 5/5 locally.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA
GH-3725 deleted `<XUnitCancellationTokenEnforced>` from every project along with
the `Directory.Build.targets` block that read it, but left the comment that
documented it behind:

    <!-- GH-3702: xUnit1051 reinstated for this project -->

It now says the opposite of the truth. xUnit1051 is not "reinstated for this
project" — it is enforced for every project by default, which was the entire
point of removing the opt-in. A new test project copied from any of these 71
would carry a comment describing a mechanism that no longer exists.

Comment removed everywhere; SlowTests' PropertyGroup held nothing else and goes
with it. Pure deletions — `wolverine.slnx` builds clean in Release with 0
warnings.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA
…-3763)

Second pass on the `Category=Flaky` ledger, using the mechanic the issue asks
for: untag, run repeatedly with no retry harness, then fix, delete, or keep the
tag with evidence.

Nine Rabbit classes carried the tag. Measured against a fresh broker on
2026-08-02, `dotnet test` directly so nothing was retried:

**Seven are stale tags — untagged.** `force_restart_listener_3232`,
`RabbitMqBrokerHealthProbe_tests`, `sending_raw_messages`, `cluster_endpoints`,
`endpoint_health_connection_state_3231`, both `send_by_topics` classes and
`Bug_189`: **5 consecutive runs, 41 tests, zero failures.**

**Two are real, and neither is "flaky".** Both keep the tag, now with the numbers
in a comment next to it so the next person does not have to re-measure:

- `multi_tenancy_through_virtual_hosts.send_message_to_a_specific_tenant` is
  deterministic in BOTH directions — 7/7 pass with the class run alone (3 runs),
  fails every time when run alongside the other Rabbit suites (3 runs). It fails
  in ~100ms against a 15s tracked-session timeout, so nothing is timing out; this
  is cross-class state on a shared broker, the #1 shape #3763 calls out. Needs
  the interfering suite identified, not another retry budget.

- `end_to_end` is one hard failure plus a genuine flake, not one flaky class:
  `send_message_to_and_receive_through_rabbitmq_with_routing_key` fails 3 of 3,
  and one of `use_direct_exchange_with_binding_key` / `use_fan_out_exchange`
  fails on every run. Both under 500ms — the exchange/binding-declaration race
  from #2618.

Worth recording: `end_to_end` was very nearly untagged with the rest, because it
was not in the filter used for the repeat runs. Untagging a class that fails 2 of
20 on every single run would have put a guaranteed red into CIRabbitMQ. Verify
each class you untag by name.

Ledger: 53 -> 45.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0116vfBcKwcjWn8msM4ZjkuA
@jeremydmiller
jeremydmiller merged commit 0d95ad0 into main Aug 2, 2026
34 checks passed
erdtsieck pushed a commit to erdtsieck/wolverine that referenced this pull request Aug 3, 2026
…asperFxGH-3763)

19 [Trait("Category", "Flaky")] tags hid 65 of the 304 tests in this project --
21% of the suite never ran. Not one of them recorded a reason, a number, or an
issue link, so there was no way to tell from the code whether any had ever been
real.

git log -L on each tag line says most were never individually judged: 15 of the
19 went in on 2026-03-20/21 across four commits with messages like "Tag all
ConventionalRouting tests as Flaky" and "tag flaky AWS/Azure SB tests". That is a
bulk sweep, not 15 investigations. The other 4 were added later alongside real
PRs (JasperFx#2588, JasperFx#3103, JasperFx#3534) and are left tagged here to be judged one at a time.

There is now a specific reason to think the sweep was measuring infrastructure
rather than tests. JasperFxGH-3781 follow-up found the emulator readiness gate was
TCP-connecting to the AMQP port while provisioning goes to the management port,
which answers 503 for ~26 seconds after the socket opens -- so any class doing
provisioning near the start of a run could fail for reasons that had nothing to
do with it. Nine of the fifteen are ConventionalRouting discovery tests, which
are exactly that shape.

This commit only removes the tags. Whether they stay off is decided by what CI
says, per class, by name -- the RabbitMQ pass in JasperFx#3780 nearly untagged a class
that fails 2 of 20 every run because it was verified as part of a set rather than
individually.

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