Skip to content

Agent assignment stalls at a few hundred of ~5650 agents and the leader goes idle (Wolverine 6.23.0, Marten multi-tenanted databases) #3698

Description

@erdtsieck

Summary

With ~5650 distributed agents (Marten event subscriptions across 512 tenant databases + one durability agent per database), Wolverine's leader never converges on a full assignment.

It converges, but at roughly 9–10 agents per minute and heavily skewed: two and a half hours after a rollout, 1481 of ~5240 agents are assigned and 1114 of those sit on the leader. Followers go 40 minutes at a stretch without gaining a single agent while the leader keeps adding to itself, and during those stretches no AssignmentChanged record is written at all — then it bursts back to ~50/s. Nodes stay healthy and no exceptions are logged. At this rate a full assignment takes about nine hours, and any rollout restarts it from scratch, so in practice most projections never run.

Two concrete leads, both detailed below:

  • 5987 dead-lettered Wolverine.Runtime.Agents.AgentsStarted messages, every one with System.UriFormatException: Invalid URI: The URI is empty. — i.e. the reply that confirms an agent start failing to parse. Dated 10–14 July, an earlier release, but on this same cluster and agent set.
  • Projection version bumps as the trigger. The previous release had none and rolled out fine; every stuck agent belongs to one of the two projections whose version changed in the release that is stuck.

The per-node counts also land on exact multiples of AgentStartBatchSize early on, which is what first made us look at the chunked assignment path.

Environment

  • WolverineFx 6.24.0, Marten 9.20.2, JasperFx 2.36.2, .NET 10, PostgreSQL 18 (AWS RDS) — verified from the running container image, not from configuration. The five nodes in the measurements below started 16:26–16:30 local, which is exactly the rollout of that build.

    (Correction: an earlier version of this issue said 6.23.0 / 9.20.0 / 2.36.1. That came from a ddpv tag inside a persisted mt_event_progression.pause_reason, which is written once and never cleared, so it named a build from earlier in the day. The stall reproduces on the current 6.24.0.)
  • IntegrateWithWolverine(opts => { opts.MainDatabaseConnectionString = ...; opts.UseWolverineManagedEventSubscriptionDistribution = true; }) — always on; we never register AddAsyncDaemon(...)
  • MultiTenantedWithShardedDatabases — 512 tenant databases on one server, ~854 tenants
  • Events.TenancyStyle = Conjoined, Events.UseTenantPartitionedEvents = true, Events.EnableExtendedProgressionTracking = true
  • 6 async projections on the main store (4 of them CompositeProjectionFor)
  • Durability.Mode is Balanced; no Durability overrides at all — AgentStartBatchSize 50, MaxAgentStartParallelism 10, StaleNodeEjectionThreshold 2
  • No external broker that provides a per-node control queue (AWS SQS only), so node-to-node control traffic uses the database control queue

Agent capabilities per node, from wolverine_nodes.capabilities: 5228–5240, of which

  • ~5100 event-subscriptions://marten/main/<host>.<db>/<projection>/all/v<n>/<tenant> — tenants × projections
  • 512 wolverinedb://postgresql/<host>/claims<N>_productie/public — one durability agent per tenant database
  • ~14 on an ancillary store

Observed

Three healthy nodes, mid-rollout. wolverine_node_assignments, count(*) per node:

node 478  100
node 479   50
node 480    0

150 total of ~5650. 100 and 50 are exact multiples of AgentStartBatchSize (50). Polled over 100 s: 97 → 99. Meanwhile 22 465 AssignmentChanged records in 5 minutes (~75/s) with the assignment table not growing.

Five healthy nodes, stable topology, no deploy in flight. After ~30 minutes:

node  capabilities  assigned
481          5228        97
483          5234        39
484          5234        39
485          5234        50
486          5240        49
                       ---
                       274

AssignmentChanged in the preceding 5 minutes: 0. AgentStarted: 51. The leader has stopped assigning with ~4970 agents unassigned.

Same five nodes, sampled twice more — nothing restarted, health_check fresh on all five throughout. Node 481 is the leader; it holds the wolverine://leader/ row in wolverine_node_assignments:

node        +20 min   +40 min   delta
481 (leader)    300       350    +253
483              39        39       0
484              39        39       0
485              50        50       0
486              49        49       0
                ---       ---
                477       527

AssignmentChanged stayed at 0 across both of those windows; AgentStarted was 101 and 50. So during those 40 minutes the table grew only for the leader's own node, and without a single AssignmentChanged record being written, while the four followers sat at exactly the counts from their first chunk.

Correction to an earlier version of this issue: I first described that as the leader having stopped for good. It has not — it grinds, in long-idle-then-burst fashion. Two and a half hours after the rollout, with the same five nodes and nothing restarted:

node        16:14   17:20   18:59
481 (leader)  100     350    1114
483            50      39      89
484             0      39      39
485             -      50     145
486             -      49      94
              ---     ---    ----
              150     527    1481   of ~5240

AssignmentChanged over the last 15 minutes of that: 44 884 (~50/s), having been 0/min for the two windows before it. So the pattern is not a hard stall but very slow, bursty, and badly skewed convergence: ~9–10 agents/minute overall, 75% of everything placed on the leader, and followers gaining nothing for 40-minute stretches. At that rate a full assignment takes on the order of nine hours, and any rollout in the meantime starts it over.

0 of the 512 wolverinedb:// durability agents are assigned in any sample, so per-database outbox/scheduled-message recovery is not running anywhere.

Effect on projections. mt_event_progression across the 512 databases: 5463 of 5823 rows with agent_status = 'Stopped', 455 of 512 databases behind their high-water mark, individual (tenant, projection) shards up to 1.7M events behind. 3000 current agents have never written a heartbeat.

Not resource pressure. The database server was idle throughout: CPU 10–34%, read latency 0.9 ms, 2.5k of 12k provisioned IOPS, EBSIOBalance 99%, 134–235 of max_connections 2400. No errors in mt_event_progression.failure_category beyond 4 unrelated read timeouts out of 5823 rows, and no AgentPaused records since earlier in the day.

Node-record event types, all-time, for completeness — there is no failure-shaped event in there at all:

AssignmentChanged    36 087 221
AgentStarted             33 239
AgentStopped             14 314
AgentPaused                  96
NodeStarted                  29
DormantNodeEjected           11
LeadershipAssumed            11

AgentStarted is still being written as I write this (most recent 17:53:37), so agents do keep starting locally — it is the assignment bookkeeping that does not spread.

Startup failures: yes — 5987 dead-lettered AgentsStarted replies

Asked whether we see failures on startup. We do, on exactly the message that confirms an agent start. wolverine_dead_letters in the Wolverine main (references) database:

message_type                              exception_type            exception_message                  count
Wolverine.Runtime.Agents.AgentsStarted    System.UriFormatException  Invalid URI: The URI is empty.      5987

Every one of the 5987 dead letters is that same message type, exception type and message — nothing else has ever dead-lettered in that database. They arrived on the database control queue:

received_at                                            source            count
dbcontrol://ea02a4a5-7bb5-425f-9634-bc04f5d631f8/      Zorgdeclaraties    3714
dbcontrol://18e57cca-2198-4952-9c20-1f134cb553be/      Zorgdeclaraties    1157
dbcontrol://7e020f79-5b09-4044-ac01-f8731a0615a4/      Zorgdeclaraties    1003
dbcontrol://d800f95b-ebb0-4fab-857f-bb7e13d46ffe/      Zorgdeclaraties     113

So a node reports "I started these agents", the leader cannot deserialize the reply because some agent Uri in it is an empty string, and the reply is discarded. The leader then has no confirmation for that batch.

Two caveats, stated plainly:

  • These are dated 10–14 July, i.e. an earlier release, not the window of the stall described above. There are no dead letters in the current window and no stuck envelopes in wolverine_incoming_envelopes / wolverine_outgoing_envelopes right now.
  • I could not decode a body to show which URI is empty — the payload is not UTF-8 (invalid byte sequence for encoding "UTF8": 0xa1), so it is a binary serializer. Happy to dump raw bytes if that helps.

What makes it worth reporting anyway: it is the same message class that has to confirm a start, failing on empty-URI parsing, in the same cluster with the same agent set. If that parse still fails now but no longer dead-letters — swallowed instead — the leader would never see confirmations, which is exactly the state the assignment table is in, and it would explain why only the leader's own local starts (which need no reply) keep landing.

Our agent URIs may be relevant to reproducing it: the database segment contains dots, e.g.

event-subscriptions://marten/main/database-productie-1.zorgdeclaraties-productie.aws.topicus.healthcare.claims95_productie/provided-cares/all/v21/01009333
wolverinedb://postgresql/database-productie-1.zorgdeclaraties-productie.aws.topicus.healthcare/claims336_productie/public

Second failure mode: connection-slot exhaustion

The shard databases also dead-letter Npgsql.PostgresException 53300: remaining connection slots are reserved for roles with privileges of the "pg_use_reserved_connections"/"rds_reserved" role — 172 of them, most recently today:

2026-07-09   2      2026-07-16  22      2026-07-24   1
2026-07-10   7      2026-07-17   4      2026-07-27   4
2026-07-12   1      2026-07-21  35      2026-07-29   7
2026-07-14   1      2026-07-22  34
2026-07-15   9

This is our own capacity problem rather than a Wolverine bug, but not the one I first assumed. The shard pools are already capped — the connection string carries Maximum Pool Size=4, Connection Idle Lifetime=30, Connection Pruning Interval=10. The exhaustion happens anyway because the cap is per pool and the pool count is per shard database, per pod: Marten's sharded tenancy builds one NpgsqlDataSource per shard database, and while projection agents are assigned with database affinity, an API pod still queries any tenant's shard on request. So the ceiling is 512 databases × 4 × 5 replicas ≈ 10 000 against max_connections 2400, and 4 is already tight enough that lowering it further is unattractive.

It is listed here because a node that cannot open a connection to a shard database cannot start that database's agents either, so it is a plausible source of failed starts feeding into the above.

The remaining shard dead letters are all application-level handler bugs of ours (NullReferenceException, a Refit 500, ApplyEventException) and unrelated.

The trigger looks like projection version bumps

Colleagues pointed out that the previous release rolled out fine, and that it carried no projection version bumps. The release that is stuck did. That holds up against the data.

Versions in the deployed release vs the one before it:

projection previous release deployed release
provided-cares V20 V21
invoices V14 V15
claim_lines V14 V14
invoicejournalentries V4 V4
import-reconciliation V2 V2

A version bump changes the agent Uri (.../provided-cares/all/v21/<tenant>), so all ~853 per-tenant shards of a bumped projection are brand-new agents that have to be assigned and started from scratch. The unbumped ones keep their URIs and their existing assignments.

How far each projection got, per mt_event_progression (a row with agent_status set means the agent ran at least once since the deploy), out of 853 advertised agents each:

projection bumped agents that ran agents behind their high-water mark
provided-cares V21 yes 119 (14%) 13
invoices V15 yes 118 (14%) 9
claim_lines V14 no 642 (75%) 0
invoicejournalentries V4 no 642 (75%) 0
import-reconciliation V2 no 642 (75%) 0

Every lagging agent in the whole cluster is one of the two bumped projections; not one of the unbumped ones is behind. The unbumped projections are three-quarters started, the bumped ones one-seventh.

One candidate mechanism, which I have not proven: both bumped composites set AsyncOptions.GateSideEffectsBehindPriorVersion = true (#480). On a version bump that makes each new agent, at start, first replay up to the prior version's progression mark in Rebuild mode before going continuous. So a bump turns ~1700 agent starts into ~1700 long-running rebuild replays, each against a different tenant partition. If an agent start has to make meaningful progress before the receiving node acks its StartAgents batch, the chunk reply would time out and the leader's walk would never be confirmed — which is what the assignment table shows. That would also explain the leader-only growth: the leader's own local starts need no ack.

If that is the mechanism, the interesting question is whether a slow or long-running agent start should be able to hold up (or silently void) the rest of the assignment walk.

History — the pre-6.23.0 livelock, and what it became

wolverine_node_records had grown to 16 GB / 36M rows in five days (that table having no retention at all is filed separately as #3701):

day AssignmentChanged AgentStarted
24 Jul 4 756 150 0
25 Jul 12 818 392 6
26 Jul 12 818 386 0
27 Jul 5 530 373 17 392
28 Jul 12 482 9 462
29 Jul 25 995 + bursts 5 344

25–26 July: 12.8M assignment decisions per day with zero agents started — the livelock the 6.20→6.23 work targets. That stopped after we deployed 6.23.0 on 27 July ~17:00, so those fixes clearly did something. We have since moved to 6.24.0, which is what the cluster ran during every measurement above.

What is left on 6.24.0 is the quieter failure: the leader converges to a stable-but-wrong state a few hundred agents in, then only trickles agents onto itself.

Two smaller things noticed in the same table:

  • NodeStarted and LeadershipAssumed rows carry nonsense node_number values (1827159984, -1841074440, -899441513) interleaved with the real ones — looks like the skeleton-node insert described in the 6.23.0 notes still leaves a trace on the record side.
  • DormantNodeEjected fires while health_check on those rows is fresh.

What I would expect

With N healthy nodes and M advertised agents, the leader keeps issuing chunks until all M are assigned, or reports why it cannot. Stopping at 274–527 of ~5240 with no error and no further AssignmentChanged looks like the chunked-assignment loop losing track of the remainder — perhaps the pending-assignment ledger suppressing chunks that were never confirmed, or a per-chunk reply timeout leaving the walk in a state the next CheckAssignmentPeriod treats as complete.

The sharpest clue is the asymmetry: the leader keeps adding agents to itself while every follower stays frozen at its first chunk, and the leader's own additions produce no AssignmentChanged records at all. That reads as the local assignment path still making progress while the remote AssignAgent path has stopped being driven — two code paths that have diverged rather than one loop that stalled.

Happy to run queries against the production tables, dump wolverine_nodes / wolverine_node_assignments / wolverine_node_records slices, or turn on debug logging on the leader — say what would help.

What we are doing meanwhile

Only making the assignment settings configurable per environment (AgentStartBatchSize, MaxAgentStartParallelism, StaleNodeEjectionThreshold, the assignment cadence) so we can try larger chunks and fewer rebalances, and looking at moving the control queue off the database onto a broker with per-node control queues. We are staying on Wolverine-managed distribution throughout — handing the daemon back to Marten's own coordination is not an option for us.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions