Agent assignment record goes stale during a handoff, and an event-subscription agent can end up running on two nodes at once

[jeremydmiller]

Summary

An event-subscription agent can end up running on two nodes at once while wolverine_nodes
credits only one of them — so nothing in the system can ever stop the extra copy. Downstream in
CritterWatch this presents as a projection that keeps building read models after an operator has
paused it, and as two async daemons writing one shard concurrently.

The repro below is in your own harness (MartenTests/Distribution). ⚠️ It reproduces the
precondition — a window where the durable assignment record disagrees with reality — but not yet the
orphan itself. The orphan is measured downstream at ~3 in 8 runs; I could not make it fall out of
this test in 24 runs across three configurations. I have listed those negative results rather than
leaving them for you to retread, and I have kept my suspected mechanism clearly marked as a pointer,
because a 100ms-poll experiment argued against it.

What is reproducible here: the durable record goes stale during a handoff

Node 1 starts alone and owns both projection agents; nodes 2 and 3 join; the leader redistributes.
Sampling in-process AllRunningAgentUris() against Storage.Nodes.LoadAllNodesAsync() every 20ms
(change-only lines):

t+806ms    IN n1=[day/all,trip/all]                  ||  DUR n1=[day/all,trip/all]
           (nodes 2 and 3 join)
t+1,783ms  IN n1=[trip/all] | n2=[]                  ||  DUR n1=[day/all,trip/all] | n2=[]   <-- n1 STOPS day
t+1,978ms  IN n1=[trip/all] | n2=[] | n3=[]          ||  DUR n1=[day/all,trip/all] | n2=[] | n3=[]
t+2,042ms  IN n1=[trip/all] | n2=[] | n3=[]          ||  DUR n1=[trip/all] | n2=[] | n3=[]   <-- record catches up
t+2,128ms  IN n1=[trip/all] | n2=[day/all] | n3=[]   ||  DUR n1=[trip/all] | n2=[day/all]

For 259ms the agent is running on no node at all, while the durable record still says node 1 owns
it. That is the window. My question is first of all whether it is intended.

What is NOT reproducible here: the orphan

Downstream (CritterWatch's EventStoreCoordinationTests, same Marten primary + AddMartenStore<T>()
ancillary shape, FirstHealthCheckExecution=250ms / HealthCheckPollingTime=500ms), the same window
is ~780ms, and inside it this happens:

t+621ms    IN n1=[trip]              ||  DUR n1=[day,trip]      <-- n1 STOPS day
           ... 35 consecutive 20ms samples, 778ms, no change ...
t+1,399ms  IN n1=[day,trip]          ||  DUR n1=[day,trip]      <-- n1 STARTS day AGAIN
t+1,421ms  IN n1=[day,trip] n2=[day] ||  DUR n1=[trip] n2=[day] <-- reassignment lands

Node 1 restarts the agent while the stale record still stands, the reassignment completes 22ms later
and starts it on node 2, and nothing stops node 1's copy. Steady state is two live agents and one
assignment record, stable indefinitely.

It is genuinely running, not a stale AgentStatus: after an operator pause that the system reported
as successful, seeding 5 new event streams produced 5 new read-model documents in 1 second.

Correlation downstream: 5 failures all with a duplicate present before the pause, 41 passes all
without — 46 runs.

⚠️ Pointer, not a diagnosis — and evidence against it

The obvious story is that a health-check tick lands inside the gap, NodeAgentController.HeartBeat
calls EvaluateAssignmentsAsync(nodes, …) with nodes read from the durable table, and the agent is
restored on the source from a record that has not caught up.

I do not believe that is sufficient, and here is why: dropping this test to
HealthCheckPollingTime = 100ms makes a tick inside the 259ms window near-certain, and it produced
no restart in 8 runs. So something more than "a tick fell in the gap" is required, and I have not
found it. Please treat the code reference above as a place to look, not as the cause.

Also unruled-out: what stops the agent at the start of the gap. I never confirmed whether that is the
leader's own stop command for the reassignment or something else.

Negative results, so you don't retread them

variation	runs	orphan?
this test as written (2 agents, 250ms/500ms)	8	no — but the 259ms gap is present
HealthCheckPollingTime = 100ms	8	no
6 agents (3 projections x 2 stores)	8	no — and the gap closes entirely; IN and DUR move in lockstep
generic IAgentFamily (FakeAgentFamily), no Marten, 3 nodes	8	no — and no gap at all; the durable record tracks in-process exactly
same, with 250ms start / 500ms stop delays on the agents	8	no

The last two are the interesting ones: with a plain agent family the durable record never lags, so
whatever opens the window looks specific to the event-subscription/Marten path rather than to agent
distribution generally.

Downstream, the reproduction is also pathologically timing-sensitive — adding 12s of settling before
the pause suppressed it 5/5, and running two probe variants in one test process suppressed it 8/8
where an exact-match filter gave 3/8. Any harness change is a variable here.

The repro

src/Persistence/MartenTests/Distribution/event_subscription_agent_orphaned_during_handoff.cs.
It asserts the orphan (so it passes today) and always prints the timeline, which is where the gap is
visible. Run it against the standard wolverine-postgresql container.

using IntegrationTests;
using JasperFx.Core;
using JasperFx.Events.Projections;
using Marten;
using MartenTests.Distribution.TripDomain;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Npgsql;
using Shouldly;
using Weasel.Postgresql;
using Wolverine;
using Wolverine.Marten;
using Wolverine.Runtime;
using Wolverine.Tracking;
using Xunit;

namespace MartenTests.Distribution;

/// <summary>
/// Reproduction: an event-subscription agent ends up RUNNING ON TWO NODES AT ONCE while the durable
/// <c>wolverine_nodes</c> table credits only one of them, so nothing can ever stop the extra copy.
///
/// <para>Shape: node 1 starts alone and owns every projection agent across a primary store and an
/// ancillary <c>AddMartenStore&lt;T&gt;()</c> store. Nodes 2 and 3 then join and the leader
/// redistributes. During the handoff an agent stops on node 1 <b>without the durable assignment
/// record changing</b>; a health-check tick then sees a record that still says node 1 owns it and
/// starts it again — correctly, given that record — and the real reassignment lands ~20ms later,
/// flipping the record to node 2 and starting it there. Nobody stops the copy that came back.</para>
///
/// <para>The health-check cadence is a MAGNIFIER, not the cause — it sets how likely a tick is to
/// land inside the gap. The gap is the defect.</para>
/// </summary>
public class event_subscription_agent_orphaned_during_handoff(ITestOutputHelper output) : IAsyncLifetime
{
    private const string PrimarySchema = "orphan_primary";
    private const string AncillarySchema = "orphan_ancillary";
    private const string Scheme = "event-subscriptions";

    private readonly List<IHost> _hosts = new();
    private readonly List<string> _timeline = new();

    public async ValueTask InitializeAsync()
    {
        await using var conn = new NpgsqlConnection(Servers.PostgresConnectionString);
        await conn.OpenAsync();
        await conn.DropSchemaAsync(PrimarySchema);
        await conn.DropSchemaAsync(AncillarySchema);
        await conn.CloseAsync();
    }

    public async ValueTask DisposeAsync()
    {
        _hosts.Reverse();
        foreach (var host in _hosts)
        {
            try
            {
                host.GetRuntime().Agents.DisableHealthChecks();
                await host.StopAsync();
                host.Dispose();
            }
            catch (Exception e)
            {
                output.WriteLine("Error shutting a host down: " + e);
            }
        }
    }

    private async Task<IHost> startHostAsync()
    {
        var host = await Host.CreateDefaultBuilder()
            .UseWolverine(opts =>
            {
                opts.Durability.Mode = DurabilityMode.Balanced;

                // Aggressive on purpose — see the class comment. The shipped defaults are 3s / 10s,
                // which makes a tick inside the handoff gap rare rather than impossible.
                opts.Durability.FirstHealthCheckExecution = 250.Milliseconds();
                opts.Durability.HealthCheckPollingTime = 500.Milliseconds();

                opts.Services.AddMarten(m =>
                {
                    m.DisableNpgsqlLogging = true;
                    m.Connection(Servers.PostgresConnectionString);
                    m.DatabaseSchemaName = PrimarySchema;
                    m.Projections.Add<TripProjection>(ProjectionLifecycle.Async);
                }).IntegrateWithWolverine(m =>
                {
                    m.UseWolverineManagedEventSubscriptionDistribution = true;
                    m.MessageStorageSchemaName = PrimarySchema;
                    m.TransportSchemaName = PrimarySchema;
                });

                opts.Services.AddMartenStore<ITripStore>(m =>
                {
                    m.DisableNpgsqlLogging = true;
                    m.Connection(Servers.PostgresConnectionString);
                    m.DatabaseSchemaName = AncillarySchema;
                    m.Projections.Add<DayProjection>(ProjectionLifecycle.Async);
                }).IntegrateWithWolverine();
            }).StartAsync();

        _hosts.Add(host);
        return host;
    }

    [Fact]
    public async Task an_event_subscription_agent_never_runs_on_two_nodes_at_once()
    {
        using var stop = new CancellationTokenSource();

        // Node 1 alone, and let it actually take both agents before anyone joins.
        await startHostAsync();
        var sampler = Task.Run(() => sampleAsync(stop.Token), TestContext.Current.CancellationToken);

        var deadline = DateTimeOffset.UtcNow.AddSeconds(60);
        while (runningUris().Distinct().Count() < 2)
        {
            DateTimeOffset.UtcNow.ShouldBeLessThan(deadline, "node 1 never took both projection agents");
            await Task.Delay(50, TestContext.Current.CancellationToken);
        }

        record("### node 1 owns both agents; nodes 2 and 3 joining");
        await startHostAsync();
        record("### node 2 started");
        await startHostAsync();
        record("### node 3 started");

        // Settle well past any legitimate transient double-run.
        await Task.Delay(15.Seconds(), TestContext.Current.CancellationToken);

        var duplicated = runningUris().GroupBy(x => x)
            .Where(g => g.Count() > 1).Select(g => g.Key).ToArray();

        await stop.CancelAsync();
        try { await sampler; } catch (OperationCanceledException) { }

        output.WriteLine("=== TIMELINE (change-only) ===");
        foreach (var line in _timeline) output.WriteLine(line);

        duplicated.ShouldBeEmpty(
            $"agent(s) {string.Join(", ", duplicated)} are running on more than one node 15s after the "
            + "cluster settled — the durable node table credits only one of them, so nothing can stop "
            + "the other. In-process: " + describeInProcess());
    }

    private IEnumerable<string> runningUris() =>
        _hosts.SelectMany(h => h.GetRuntime().Agents.AllRunningAgentUris()
            .Where(u => u.Scheme == Scheme).Select(u => u.ToString()));

    private static string Short(Uri uri) => string.Join("/", uri.Segments
        .Select(s => s.Trim('/')).Where(s => s.Length > 0).TakeLast(2));

    private string describeInProcess() => string.Join(" | ", _hosts.Select(h =>
        $"n{h.GetRuntime().Options.Durability.AssignedNodeNumber}=[" +
        string.Join(",", h.GetRuntime().Agents.AllRunningAgentUris()
            .Where(u => u.Scheme == Scheme).Select(Short).OrderBy(x => x)) + "]"));

    private void record(string line) { lock (_timeline) _timeline.Add(line); }

    private async Task sampleAsync(CancellationToken token)
    {
        var last = "";
        var start = DateTimeOffset.UtcNow;
        while (!token.IsCancellationRequested)
        {
            try
            {
                var inProc = describeInProcess();

                var nodes = await _hosts[0].GetRuntime().Storage.Nodes
                    .LoadAllNodesAsync(CancellationToken.None);
                var durable = string.Join(" | ", nodes.OrderBy(n => n.AssignedNodeNumber).Select(n =>
                    $"n{n.AssignedNodeNumber}=[" +
                    string.Join(",", n.ActiveAgents.Where(u => u.Scheme == Scheme)
                        .Select(Short).OrderBy(x => x)) + "]"));

                // Change-only: a fixed-rate dump of a stable state buries the transition.
                var line = $"IN {inProc}  ||  DUR {durable}";
                if (line != last)
                {
                    record($"t+{(DateTimeOffset.UtcNow - start).TotalMilliseconds:N0}ms  {line}");
                    last = line;
                }
            }
            catch
            {
                // A host mid-start can throw here; sampling is best-effort by design.
            }

            await Task.Delay(20, token);
        }
    }
}

Environment

• main @ c25db7d9e
• Wolverine + Marten managed event-subscription distribution, DurabilityMode.Balanced, Postgres
  message store, 3 nodes
• Downstream observation: CritterWatch, Wolverine 6.31 / Marten 8.35

[jeremydmiller]

Both tests, self-contained — the repro and its negative control

Adding the negative control as runnable code, since the table above only asserted its result. The
two together are the whole argument: same cluster shape, same aggressive cadence, same 20ms sampler —
one shows a stale-record window and the other does not.

How to run

Standard wolverine-postgresql container (localhost:5433), then:

dotnet test src/Persistence/MartenTests -f net9.0 --filter "FullyQualifiedName~event_subscription_agent_orphaned_during_handoff" --logger "console;verbosity=detailed"
dotnet test src/Testing/SlowTests     -f net9.0 --filter "FullyQualifiedName~agent_handoff_control_generic_family"          --logger "console;verbosity=detailed"

Both PASS today. Neither asserts the window — they assert the orphan, which I could not make fall
out of this harness. What you want is the === TIMELINE === block each one prints; the difference
between them is the finding. Use verbosity=detailed or the output is swallowed.

What the two timelines look like on the same machine

Marten repro — a 259ms window where the agent runs nowhere and the record still points at node 1:

t+1,783ms  IN n1=[trip/all] | n2=[]  ||  DUR n1=[day/all,trip/all] | n2=[]   <-- n1 STOPS day
t+1,978ms  IN n1=[trip/all] | n2=[] | n3=[]  ||  DUR n1=[day/all,trip/all] | n2=[] | n3=[]
t+2,042ms  IN n1=[trip/all] | n2=[] | n3=[]  ||  DUR n1=[trip/all] | n2=[] | n3=[]   <-- record catches up
t+2,128ms  IN n1=[trip/all] | n2=[day/all] | n3=[]  ||  DUR n1=[trip/all] | n2=[day/all] | n3=[]

Generic-family control — IN and DUR change in the SAME sample, throughout:

t+1,859ms  IN n1=[agent-000,agent-001] | n2=[] | n3=[]  ||  DUR n1=[agent-000,agent-001] | n2=[] | n3=[]
t+2,291ms  IN n1=[agent-000] | n2=[] | n3=[]            ||  DUR n1=[agent-000] | n2=[] | n3=[]
t+3,458ms  IN n1=[agent-000] | n2=[agent-001] | n3=[]   ||  DUR n1=[agent-000] | n2=[agent-001] | n3=[]

⚠️ The control carries 250ms start / 500ms stop delays on its agents deliberately, so it cannot be
dismissed as "the fake agent is too fast to have a window". FakeAgent.StartCount is asserted too, so
a re-start would be caught even if it left no trace in the sampled state.

The control: src/Testing/SlowTests/Agents/agent_handoff_control_generic_family.cs

It also carries DelayedAgentFamily, a small IStaticAgentFamily that can express a stop cost —
the shipped FakeAgentFamily has StartDelayPolicy but no stop delay, and the stop is the half that
would open the window if one existed here.

using IntegrationTests;
using JasperFx.Core;
using JasperFx.Resources;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Npgsql;
using Shouldly;
using Weasel.Postgresql;
using Wolverine;
using Wolverine.ComplianceTests;
using Wolverine.Postgresql;
using Wolverine.Runtime;
using Wolverine.Runtime.Agents;
using Wolverine.Tracking;
using Xunit;

namespace SlowTests.Agents;

/// <summary>
/// NEGATIVE CONTROL for the orphaned-agent report. Same cluster shape and the same aggressive
/// health-check cadence as the Marten repro
/// (<c>MartenTests/Distribution/event_subscription_agent_orphaned_during_handoff</c>), but over a
/// plain <see cref="IAgentFamily" /> with no event store involved.
///
/// <para>It PASSES, and more importantly its timeline shows <b>no stale-record window at all</b>:
/// the durable <c>wolverine_nodes</c> record and the in-process running-agent set change in the same
/// 20ms sample throughout the handoff. The Marten repro on the same machine shows a ~259ms window in
/// which an agent has stopped on the source node while the record still credits it.</para>
///
/// <para>That contrast is the point of this file: it argues the window is specific to the
/// event-subscription path rather than to agent distribution generally, and it holds with agent
/// start/stop costs dialled in (below), which was the first thing I suspected.</para>
/// </summary>
[Collection("agent_scale")]
public class agent_handoff_control_generic_family : IAsyncLifetime
{
    private const string SchemaName = "agent_handoff_control";
    private const string Scheme = "control";
    private const int AgentCount = 2;

    // A real daemon shard is not free to start or stop. Set deliberately so this control cannot be
    // dismissed as "the fake agent is too fast".
    private static readonly TimeSpan StartDelay = 250.Milliseconds();
    private static readonly TimeSpan StopDelay = 500.Milliseconds();

    private readonly ITestOutputHelper _output;
    private readonly List<IHost> _hosts = new();
    private readonly List<DelayedAgentFamily> _families = new();
    private readonly List<string> _timeline = new();

    public agent_handoff_control_generic_family(ITestOutputHelper output) => _output = output;

    public async ValueTask InitializeAsync()
    {
        await using var conn = new NpgsqlConnection(Servers.PostgresConnectionString);
        await conn.OpenAsync();
        await conn.DropSchemaAsync(SchemaName);
        await conn.CloseAsync();
    }

    public async ValueTask DisposeAsync()
    {
        _hosts.Reverse();
        foreach (var host in _hosts)
        {
            try
            {
                host.GetRuntime().Agents.DisableHealthChecks();
                await host.StopAsync();
                host.Dispose();
            }
            catch (Exception e)
            {
                _output.WriteLine("Error shutting a host down: " + e);
            }
        }
    }

    private Task<IHost> startHostAsync()
    {
        return Host.CreateDefaultBuilder()
            .UseWolverine(opts =>
            {
                opts.Durability.Mode = DurabilityMode.Balanced;
                opts.Durability.FirstHealthCheckExecution = 250.Milliseconds();
                opts.Durability.HealthCheckPollingTime = 500.Milliseconds();

                var family = new DelayedAgentFamily(Scheme, AgentCount, StartDelay, StopDelay);
                lock (_families) _families.Add(family);
                opts.Services.AddSingleton<IAgentFamily>(family);

                opts.PersistMessagesWithPostgresql(Servers.PostgresConnectionString, SchemaName);
                opts.Services.AddResourceSetupOnStartup();
            }).StartAsync();
    }

    [Fact]
    public async Task the_durable_record_never_lags_the_in_process_agents_for_a_plain_family()
    {
        using var stop = new CancellationTokenSource();

        _hosts.Add(await startHostAsync());
        var sampler = Task.Run(() => sampleAsync(stop.Token), TestContext.Current.CancellationToken);

        var deadline = DateTimeOffset.UtcNow.AddSeconds(60);
        while (runningUris().Distinct().Count() < AgentCount)
        {
            DateTimeOffset.UtcNow.ShouldBeLessThan(deadline, "node 1 never took the family");
            await Task.Delay(50, TestContext.Current.CancellationToken);
        }

        record("### node 1 owns the family; nodes 2 and 3 joining");
        _hosts.Add(await startHostAsync());
        record("### node 2 started");
        _hosts.Add(await startHostAsync());
        record("### node 3 started");

        await Task.Delay(15.Seconds(), TestContext.Current.CancellationToken);

        var duplicated = runningUris().GroupBy(x => x)
            .Where(g => g.Count() > 1).Select(g => g.Key).ToArray();

        // StartCount > 1 is the direct evidence of a RE-START rather than a merely slow stop.
        var restarted = _families
            .SelectMany(f => f.Agents.Select(a => (a.Uri, a.StartCount)))
            .Where(x => x.StartCount > 1)
            .Select(x => $"{x.Uri} startCount={x.StartCount}")
            .ToArray();

        await stop.CancelAsync();
        try { await sampler; } catch (OperationCanceledException) { }

        _output.WriteLine("re-started agents: " + (restarted.Any() ? string.Join(", ", restarted) : "(none)"));
        _output.WriteLine("=== TIMELINE (change-only; IN = in-process, DUR = wolverine_nodes) ===");
        foreach (var line in _timeline) _output.WriteLine(line);

        duplicated.ShouldBeEmpty($"agent(s) {string.Join(", ", duplicated)} ran on more than one node");
        restarted.ShouldBeEmpty("no agent should have been re-started during a clean handoff");
    }

    private IEnumerable<string> runningUris() =>
        _hosts.SelectMany(h => h.GetRuntime().Agents.AllRunningAgentUris()
            .Where(u => u.Scheme == Scheme).Select(u => u.ToString()));

    private string describeInProcess() => string.Join(" | ", _hosts.Select(h =>
        $"n{h.GetRuntime().Options.Durability.AssignedNodeNumber}=[" +
        string.Join(",", h.GetRuntime().Agents.AllRunningAgentUris()
            .Where(u => u.Scheme == Scheme).Select(u => u.Host).OrderBy(x => x)) + "]"));

    private void record(string line) { lock (_timeline) _timeline.Add(line); }

    private async Task sampleAsync(CancellationToken token)
    {
        var last = "";
        var start = DateTimeOffset.UtcNow;
        while (!token.IsCancellationRequested)
        {
            try
            {
                var inProc = describeInProcess();

                var nodes = await _hosts[0].GetRuntime().Storage.Nodes
                    .LoadAllNodesAsync(CancellationToken.None);
                var durable = string.Join(" | ", nodes.OrderBy(n => n.AssignedNodeNumber).Select(n =>
                    $"n{n.AssignedNodeNumber}=[" +
                    string.Join(",", n.ActiveAgents.Where(u => u.Scheme == Scheme)
                        .Select(u => u.Host).OrderBy(x => x)) + "]"));

                var line = $"IN {inProc}  ||  DUR {durable}";
                if (line != last)
                {
                    record($"t+{(DateTimeOffset.UtcNow - start).TotalMilliseconds:N0}ms  {line}");
                    last = line;
                }
            }
            catch
            {
                // A host mid-start can throw here; sampling is best-effort by design.
            }

            await Task.Delay(20, token);
        }
    }
}

/// <summary>
/// A <see cref="FakeAgent" /> family that can express BOTH a start and a stop cost, and hands its
/// built agents back so a test can read <see cref="FakeAgent.StartCount" />. The shipped
/// <c>FakeAgentFamily</c> exposes a start-delay policy but no stop delay, and the stop is the half
/// that would open a handoff window if one existed here.
/// </summary>
public class DelayedAgentFamily : IStaticAgentFamily
{
    private readonly Uri[] _uris;
    private readonly TimeSpan _startDelay;
    private readonly TimeSpan _stopDelay;
    private readonly List<FakeAgent> _agents = new();

    public DelayedAgentFamily(string scheme, int agentCount, TimeSpan startDelay, TimeSpan stopDelay)
    {
        Scheme = scheme;
        _startDelay = startDelay;
        _stopDelay = stopDelay;
        _uris = Enumerable.Range(0, agentCount).Select(i => new Uri($"{scheme}://agent-{i:D3}")).ToArray();
    }

    public string Scheme { get; }

    public IReadOnlyList<FakeAgent> Agents
    {
        get { lock (_agents) return _agents.ToArray(); }
    }

    public ValueTask EvaluateAssignmentsAsync(AssignmentGrid assignments)
    {
        assignments.DistributeEvenly(Scheme);
        return new ValueTask();
    }

    public ValueTask<IReadOnlyList<Uri>> AllKnownAgentsAsync()
        => ValueTask.FromResult((IReadOnlyList<Uri>)_uris);

    public ValueTask<IReadOnlyList<Uri>> SupportedAgentsAsync()
        => ValueTask.FromResult((IReadOnlyList<Uri>)_uris);

    public ValueTask<IAgent> BuildAgentAsync(Uri uri, IWolverineRuntime runtime)
    {
        lock (_agents)
        {
            var existing = _agents.FirstOrDefault(x => x.Uri == uri);
            if (existing != null) return new ValueTask<IAgent>(existing);

            var agent = new FakeAgent(uri) { StartDelay = _startDelay, StopDelay = _stopDelay };
            _agents.Add(agent);
            return new ValueTask<IAgent>(agent);
        }
    }
}

Where I would look next, and what I have already ruled out

The window exists on the event-subscription path and not on the plain-family path, with everything
else held constant. It also closes when the same Marten test runs 6 agents instead of 2 (IN and
DUR move in lockstep), which I do not have an explanation for and which I would not have predicted.

⚠️ Repeating the caution from the issue body because it is the thing most likely to waste your time:
the health-check-tick story is not sufficient. HealthCheckPollingTime = 100ms makes a tick
inside the 259ms window near-certain and produced 0 re-starts in 8 runs. Something else is
required for the source node to bring the agent back, and I did not find it.

[jeremydmiller]

The orphan is ~75% reproducible, not intermittent — and "intermittent" was an artifact of watching one agent

Downstream re-measurement (CritterWatch EventStoreCoordinationTests, 16 runs on a fresh fleet,
2026-09-02). This changes the denominator, and I think it invalidates some of the negative results
already recorded on this issue — including two of mine.

The mistake that produced "intermittent"

The leader reassigns exactly one event-subscription agent as nodes 2 and 3 join, and which one
varies per run. The failing downstream test pauses the ancillary Day agent, so every run where the
leader happened to move main/trip/all instead scored as a pass — with an unobserved orphan
sitting on the primary store's agent. My own first probe repeated the error and scored those as clean
controls.

Watching both agents instead:

runs	16
orphaned	12 (75%)
of those, on main/trip/all (PRIMARY store)	8
of those, on the ancillary store	4

So it is not ancillary-specific and not rare. I suspect this also explains the "5 failures in
the first ~9 runs, then 41 consecutive passes" recorded downstream.

An exact discriminator, 16 of 16

Wolverine already persists everything needed — a NodeRecord per agent transition, and one per
dispatched command with Description = command.ToString(). Reading them back after the fact (no
instrumentation added — see the caveat below):

Orphan run — the source node logs a second AgentStarted in the same millisecond as its AgentStopped:

t+  769ms | n1 | AgentStarted      | main/trip/all
t+1,301ms | n1 | AssignmentChanged | ReassignAgent { trip/all, n1 -> n2 }
t+2,086ms | n1 | AgentStarted      | main/trip/all      <-- second start on the SOURCE
t+2,086ms | n1 | AgentStopped      | main/trip/all
t+2,113ms | n2 | AgentStarted      | main/trip/all

Clean run — a lone stop, no second start:

t+  786ms | n1 | AgentStarted      | day/all
t+1,848ms | n1 | AssignmentChanged | ReassignAgent { day/all, n1 -> n2 }
t+2,178ms | n1 | AgentStopped      | day/all
t+2,220ms | n2 | AgentStarted      | day/all

Every run with the extra start orphaned. Every run without it handed off cleanly. 16/16.

The timing is bimodal with zero overlap

	reassignment decided	stop lands	gap
orphan (12)	1,293–1,314 ms	2,078–2,108 ms	782–795 ms
clean (4)	1,848–1,902 ms	2,158–2,196 ms	264–330 ms

The stop always lands at ~2.08–2.20 s. With the fixture's FirstHealthCheckExecution = 250ms /
HealthCheckPollingTime = 500ms, ticks fall at ~250/750/1,250/1,750/2,250 ms — so the two modes are
simply which tick made the decision, and the earlier one leaves a ~785 ms window instead of ~285 ms.

🩸 This argues AGAINST the tick-in-the-gap mechanism, including my own earlier pointer

The obvious reading of the bimodality is "a later health-check tick lands inside the longer window and
re-issues a start". The same data says otherwise: the leader's AssignmentChanged log contains
no command at all inside the gap, and a leader-issued start would be recorded there. That is
consistent with the earlier finding that HealthCheckPollingTime = 100ms produced no restart in 8 runs.

So the window length correlates perfectly, but the leader is not visibly acting inside it. The
second start landing in the same millisecond as the stop points at the stop path rather than at
the leader — but I have not measured that and am recording it as a pointer, not a diagnosis. Three
mechanisms have now failed their own tests on this issue; I would rather hand over a sharp repro than
a fourth story.

One structural note, from reading rather than measuring

AssignmentGrid.WithNode seeds Agent.OriginalNode from wolverineNode.ActiveAgents — the durable
record — and RecordDuplicateAgent only fires when two nodes' durable rows both claim an agent. So
the GH-2602 split-brain healer cannot see this class of duplicate by construction: it is one durable
row and two live in-process copies. That may be worth addressing independently of the cause, since it is
why the orphan never self-heals.

Reproducing it

CritterWatch 3205b9ff adds src/EventStoreCoordinationTests/OrphanedAgentCommandProbe.cs. No pause
is needed — the orphan is present as soon as formation completes — so a run is ~15 s rather than a
full pause/restart cycle. It asserts nothing about the orphan on purpose: a non-reproducing run is the
control, and a red assertion would hide it.

⚠️ Caveats on reading the dump. Cascaded commands (the AssignAgent that ReassignAgent returns)
never reach AssignmentsChanged, so they are absent — which is why the destination's start has no
command record either, and why "no command in the gap" bounds the leader's behaviour rather than
every dispatch. Same-millisecond records cannot be ordered from NodeRecord.Timestamp, so I cannot say
whether the second start preceded or followed the stop. And presence is measured from
AllRunningAgentUris(); that the duplicate is real rather than a reporting artifact comes from the
earlier downstream observation of two daemons writing the same shard concurrently
(ProgressionProgressOutOfOrderException).

[jeremydmiller]

Answered: the second start is GH-4193's wedged-shard sweep, racing an in-flight deliberate stop

Measured, not inferred. Wolverine's own logs name the path; capturing them on each node (4 of 4
instrumented runs, identical):

t+1,308ms  AssignmentChanged  ReassignAgent { trip/all, n1 -> n2 }
t+2,051ms  Agent trip/all on node 1 is still assigned here but its shard is stopped
           with no failure reported; restarting it            <-- restartWedgedLocalAgentAsync
t+2,051ms  Agent trip/all is still registered on node 1 but its shard is stopped;
           restarting it                                       <-- StartAgentAsync, GH-3519 recovery
t+2,330ms  Successfully stopped agent trip/all on node 1       <-- StopAgentAsync FINALLY returns
t+2,330ms  Successfully started agent trip/all on Node 1       <-- THE ORPHAN
t+2,332ms  Successfully stopped agent trip/all on node <n1>    <-- ReassignAgent's stop confirmed
t+2,352ms  Successfully started agent trip/all on Node 2       <-- the cascaded AssignAgent

The mechanism

ReportFailedLocalAgentsAsync runs on every node on every health-check tick, and calls
restartWedgedLocalAgentAsync for any locally-registered IEventSubscriptionAgent found Stopped
with no failure. GH-4193's own comment states the assumption that does not hold:

"The old comment's other reason — 'would fire on every stop' — does not hold for an agent still
present in Agents: StopAgentAsync removes it from the dictionary and drops the assignment row, so
Stopped-and-still-registered is BY CONSTRUCTION a wedged shard and never a deliberate stop."

It is a deliberate stop, mid-flight. NodeAgentController.StopAgentAsync:

await agent.StopAsync(_cancellation.Token);   // ~280-305ms for a Marten shard, measured
Agents.TryRemove(agentUri, out _);            // removal happens only AFTER

and EventSubscriptionAgent.Status delegates to the daemon's inner agent
(_status == Stopped ? Stopped : _innerAgent?.Status ?? _status), which reaches Stopped inside
_daemon.StopAgentAsync(...) — while _status is still set only after it returns.

So for the whole duration of the daemon stop the agent is Stopped and still registered, which is
exactly the state the sweep treats as proof of a wedge. A tick landing in that window restarts the
agent the reassignment is in the middle of moving away, and ReassignAgent then confirms its stop and
starts the destination copy — two live daemons, one durable record.

Measured windows: 279 ms, 275 ms, 305 ms across runs (sweep line → StopAgentAsync success line).

This resolves the results that did not previously fit

• "A generic IAgentFamily shows no gap at all." The sweep opens with
  if (entry.Value is not IEventSubscriptionAgent) { continue; } — it cannot fire for a generic
  family. So the HealthCheckPollingTime = 100ms → 0-restarts-in-8 result, which I offered as
  evidence against the health-check story, was run in a configuration where this mechanism is
  unreachable. It did not disprove the tick hypothesis; it could not test it.
• Why it looks Marten/event-subscription-specific. Same gate, and the window itself is the Marten
  daemon stopping a shard. A fake agent stops in microseconds, so the window is ~0.
• The bimodal timing I reported (orphan runs decide the reassignment at 1,293–1,314 ms, clean runs
  at 1,848–1,902 ms) is just whether a health-check tick falls inside the ~280 ms stop window.
• Why it never self-heals: AssignmentGrid.WithNode seeds OriginalNode from the durable
  ActiveAgents, and RecordDuplicateAgent only fires when two nodes' durable rows claim the same
  agent. One row, two live copies is invisible to the Leader split-brain: stale Postgres advisory lock causes two leaders to assign agents concurrently #2602 healer by construction.

⚠️ Correcting myself twice on this issue: I offered the tick-in-the-gap idea, then argued against
it from "the leader emits no command in the gap". Both were wrong in the same way — the restart is
node-local and never goes through the leader at all, so the leader's command log was never going to
show it, and its silence was not evidence.

Fix direction — a pointer, not a patch

The sweep needs to distinguish "my shard wedged" from "I am being stopped". StopAgentAsync already
stamps _stopRevocations[agentUri] before doing anything, precisely so an in-flight start can be
revoked (GH-3748) — the sweep simply does not consult it. A "stop in flight for this agent" marker
cleared in StopAgentAsync's finally would be the smallest thing that closes it; reusing
_stopRevocations directly does not work as-is, since nothing clears it and it carries no notion of
"still running". Removing from Agents before awaiting StopAsync would also close the window, but
changes what a concurrent StartAgentAsync sees, so it is the more invasive of the two.

Whether the ~280 ms daemon stop should also be shortened is a separate question; the race exists at any
window length.

Reproducing

CritterWatch ec829f74 — src/EventStoreCoordinationTests/OrphanedAgentCommandProbe.cs plus
AgentLogCapture.cs. ~15 s per run, no pause needed. Instrumentation did not suppress it: 4/4
orphaned with log capture on, against 12/16 without — worth stating explicitly, since suppression by
instrumentation has bitten this investigation twice.

[jeremydmiller]

Downstream confirmation: b8d1926af closes the CritterWatch case. 0 failures in 16 runs.

The original report here came from CritterWatch's cluster_ancillary_pause_then_restart — a 3-node cluster where a paused ancillary event-subscription agent keeps running on the source node while the durable node table credits only that one copy, so nothing can ever stop the extra one.

Since b8d1926af is merged but not yet in a release, I cherry-picked it onto V6.32.0, packed WolverineFx 6.32.1-gh4240.1 locally, and measured against the real downstream repro rather than a synthetic one.

Wolverine	Runs	Failures
V6.32.0 stock	8	2
V6.32.0 + b8d1926af	16	0

Same machine, fresh container fleet before each block, same exact-name test filter. At the ~25% rate measured on stock, P(0 in 16) is about 1%.

Worth stating plainly: this does not prove the rate is zero, and I am not claiming it does. What makes it more than a favourable coin is that the fix is precisely what the downstream diagnosis had predicted would be needed — claiming the stop before any of it is observable, and clearing it in a finally — so the ~275-305 ms window in which an agent is registered, Stopped, and reporting no failure is no longer indistinguishable from the wedged shard ReportFailedLocalAgentsAsync exists to restart.

Two notes that may be useful to whoever releases this:

• The _stoppingAgents marker rather than early deregistration is the right call, and the comment in the fix says why better than the issue did: AllRunningAgentUris() answers the leader's QueryAgentPresence probe, so an agent must keep answering "still here" through its own teardown or the leader reads a confirmed stop and starts the destination copy while the source is still winding down. Deregistering up front would have traded this bug for that one.
• The earlier HealthCheckPollingTime = 100ms null in this thread was a false negative, for a reason worth recording: it was run against a generic IAgentFamily, and the sweep opens with if (entry.Value is not IEventSubscriptionAgent) { continue; } — so it could not fire in that configuration. That null disproved nothing and is what sent the investigation away from the right neighbourhood for a while.

Nothing needed changing downstream. CritterWatch's tracker (JasperFx/CritterWatch#1192) stays open only until this ships in a release.