Silo saturated in its first minutes after boot — partition-bootstrap reads of two compile-activity creates reach no verdict (1,397 stale subscribes, ThreadPool shortage)

Closed
#7,702 0 comments 0 reactions 0 assignees View on GitHub

Maintainers usually reply within 1 day

Nobody has claimed this yet.

Assessment

Difficulty
4/5
Estimated time
3-5 days
Newbie friendliness
35/100
Issue type
Bug
Clarity
Mostly clear
Activity status
Active
Tech stack
csharp

Research direction

Start with MeshWeaver.Plugins Store/Licensing/Source/PluginGate.cs and SeedGating to trace concurrency across plugin passes and whether targeted reads are bounded. Then capture a Sample or GC/ThreadPool counters during a replica’s first five minutes, as the issue describes. Done means identifying which candidate cause dominates before proposing a code change.

Written by the indexing model from the issue text.

Description

bug sev:H

Observed. On pod memex-portal-deployment-6bc77c9846-wgm7m (namespace memex-cloud), two CreateNode requests stalled at stage partition-bootstrap at 2026-10-30 00:46:12Z. Both targets were compile-activity nodes: Hosting/FleetConsole/_Activity/compile-202610300045394021… and Hosting/IntegrationsApp/_Activity/compile-202610300045394021…. The pod had logged Application started at 00:41:23Z, 4 min 49 s earlier.

This was folded into #7464 as fingerprint 542746fe6fbc502d (log site f205e0da8dbd21ba, incident Admin/_LogIncident/542746fe6fbc502d). #7464 is about a different stage (write) and a different caller (a bulk part import). That half is fixed, and #7464 closes on its own verification. This issue takes the boot half.

What the pod log shows. The partition-bootstrap reads are not the defect. The whole silo was saturated in its first five minutes, and every bootstrap read waited in the same queue as everything else.

All lines below were read through governed Logs actions on the control instance:

Time (UTC) Line
00:41:23 Application started
00:41:48 → 00:46:52 [ROUTE] Routing back-pressure crossings, about 60 episodes. Each reads routing pool subscribing 0, waiting for a pool slot 32–97 (for example 55 at 00:41:55, 51 at 00:45:30, 50 at 00:46:04, 97 at 00:46:38). deepest per-channel queue 0 throughout. Oldest leg dispatched 9 ms → 11.7 s (Feedback/Digests at 00:46:15).
00:41:52 → 00:45:38 Prebuilt assembly for … DECLINED before writing (#2813). This hit about 40 NodeTypes, mostly Hosting/* and Store/* (bundle 1.73.7 against live 1.74, source fingerprint mismatch).
00:42:10 ShippedPrebuiltBundles: 303 prebuilt assembly(ies) from 73 shipped bundle(s) …
00:43:01 → 00:43:11 DynamicTypePreWarmer: 1 of 436 dynamic NodeType(s) need building. The batch source discovery (nodeType:Code partitions:all limit:25000, then */Source and */Test) resolved 6,843 Code nodes.
00:43:09, 00:45:35 Compile recovery: Hosting/FleetConsole (and Hosting/IntegrationsApp) came up persisted as Compiling — re-triggering compile. This happened twice, so each type's hub activated twice in 2.5 minutes.
00:44:25 DynamicTypePreWarmer: warm-up complete in 00:03:01 — compiled=0 alreadyBaked=435 compileErrors=1 … — managed +3984 MB, working set +5542 MB
00:44:34 → 00:44:49 [DefaultInstall] pass
00:45:57 → 00:46:05+ [PluginGating] the live subtree query of <plugin> failed (re-open 1) — it re-opens in 00:01:00. At least 20 plugins hit this within 8 s.
00:46:04 Cell-surface single-home gate for 'Hosting/FleetConsole': the owning NodeType 'Hosting/Build' could not be read (absent or stalled)
00:46:12 The two LifecycleVerdictStalledException … stage 'partition-bootstrap'
00:46:13 → 00:46:43 [STALE-CALLBACK] cache/olDnuENkQE23Fkp7BV43Lg: N callback(s) pending > 30000ms, with N = 859 → 1397 → 1118 → 978 → 627 → 329 → 231. It drains, so the slots are not leaked.
00:46:13 Hub Hosting/IntegrationsApp/Source/IntegrationsAppTexts deferred SubscribeRequest … for >30s; initialization gates closed: [DataContextInit,MeshNodeInit]
00:46:18 DeliveryFailureException … Orleans deactivating grain … DirectoryFailure — server S10.244.12.148:11111 entered status ShuttingDown. A roll was replacing another replica at the same moment.

What the 1,397 stale callbacks were (the 00:46:17 line, classified by path shape): all SubscribeRequests from the pod's one stream-cache hub.

  • 526 were {plugin}/_Entitlements/* markers: 444 per-viewer, plus 82 _Entitlements/_Policy.
  • 93 were {root}/_Policy.
  • 98 were bare partition roots.
  • 298 were */Source/* or */Test/* Code nodes.
  • About 380 were other nodes (Admin/*, Hosting/*, samples, and so on).

Every one is a point read that activates its own per-node hub. The partition-bootstrap reads of the two creates (partition root, creator grant, GitSync ownership) went into the same cache hub and queued behind them.

Reading per Reading a Routing Saturation Report.

  • waiting for a pool slot sat high while subscribing was at 0. That means legs were accepted and had not yet started (IoPool.InvokeCore runs each leg SubscribeOn(TaskPoolScheduler.Default)), which is a ThreadPool shortage, not a slot cap and not a leaked leg.
  • Every oldest leg was inside LegSelfBound.
  • So the routing line is the instrument that noticed, not the cause.

Candidate causes, and the reading that separates them.

  1. GC / memory pressure from the warm-up. The warm-up grew the managed heap by +3,984 MB (working set +5,542 MB) to compile zero types. It loaded 435 already-baked types and 303 bundle assemblies and resolved 6,843 Code nodes. Blocking gen2 collections over a heap that size suspend every thread, which looks exactly like "accepted, not started".
    • Separating reading: dotnet-counters / the GC metrics of a freshly booted replica (% time in GC, gen2 count, pause time) over its first 5 minutes. Alternatively, the LocalSiloHealthMonitor lines. No .NET Thread Pool execution stalled line was logged on this pod before 01:21:24Z, even though the regex covered the whole window. Either the monitor was not yet sampling, or the stalls stayed under its 1 s threshold.
  2. Unbounded boot fan-out of point reads by the Plugins gating pass. PluginGating runs for every installed plugin, apparently all at once (≥ 20 subtree-query failures within 8 s). Each pass also issues targeted per-viewer reads (PluginGate.RetractionCandidates, already narrowed once by MeshWeaver#6623). The 526 entitlement / policy subscribes fit that shape.
    • Separating reading: the PluginGating code path's concurrency across plugins (MeshWeaver.Plugins Store/Licensing/Source/PluginGate.cs, SeedGating), and whether a pass's targeted reads are MergeBounded or hot. A hot Observe under a bound is the shape that #7568 and Plugins#4566 already fixed elsewhere.
  3. Activation churn from the concurrent roll. Hubs whose directory owner was shutting down were deactivated and re-activated (DirectoryFailure at 00:46:18). The double Compile recovery … came up persisted as Compiling shows the two compiling NodeType hubs re-activating at 00:43:09 and 00:45:35.
    • Separating reading: the same window on a replica that booted with no other replica shutting down.

Not established.

  • Which of the three dominates. No CPU, GC or ThreadPool-queue metric for this pod is in the evidence. Only log lines were read.
  • Who issued the 298 Source/Test and ~380 other subscribes. The candidates are the warm-up's activation-driven leg, cell-surface gates and the PluginGating passes. The stale-callback line names targets, not callers.
  • Whether the two activity nodes landed late. They were not read.
  • Whether readiness was gated on the warm-up on this replica. If it was not, traffic was admitted while the warm-up ran.
  • Whether it recurs on every boot or only on a boot during a roll. Only this one boot was read.
  • The boot-issuers read was CUT at 300 lines, so PluginGating lines after 00:46:05 were not all seen.

What was ruled out.

  • A stuck or leaked routing slot: every oldest leg was within its bound, and the stale callbacks drained from 1,397 to 231 in 30 s.
  • A partition-bootstrap-specific defect: those reads simply waited in the shared queue.
  • The write-stage starvation fixed for #7464 (Plugins#4566, #7568): a different caller and stage.
  • The compile-on-ThreadPool defect: the warm-up compiled 0 types, and Compiling Off the ThreadPool already moved emits to the CPU lane.

Next instrument. A Sample of the next replica to boot on memex-cloud during its first 5 minutes, or the process's GC/ThreadPool counters if the host exports them. Then decide between candidates 1 and 2 before changing code. No bound should be raised to make this go away.

Refs #7464.

Dominant language
C#
Stars
12
Forks
5
Avg merge
5h 10m
Merged PRs (30d)
980

Getting set up

  • No Dockerfile or Docker Compose file
  • Has a pull request template
  • No contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from Systemorph/MeshWeaver

All issues in Systemorph/MeshWeaver

Similar issues

More C# issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.